[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:18.586601 27943 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.73.254:36719
I20260812 06:19:18.587622 27943 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:18.588236 27943 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:18.594959 27953 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:18.595031 27957 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:18.595105 27943 server_base.cc:1061] running on GCE node
W20260812 06:19:18.595206 27951 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:18.595808 27943 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:18.595899 27943 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:18.595954 27943 hybrid_clock.cc:648] HybridClock initialized: now 1786515558595951 us; error 0 us; skew 500 ppm
I20260812 06:19:18.597770 27943 webserver.cc:533] Webserver started at http://127.27.73.254:34961/ using document root <none> and password file <none>
I20260812 06:19:18.598520 27943 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:18.598641 27943 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:18.598929 27943 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:18.600634 27943 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/master-0-root/instance:
uuid: "1ee47099f01c480e9ffa1fe21ba3fa60"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-jztv"
I20260812 06:19:18.604287 27943 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:18.606551 27966 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.607506 27943 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:19:18.607643 27943 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/master-0-root
uuid: "1ee47099f01c480e9ffa1fe21ba3fa60"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-jztv"
I20260812 06:19:18.607751 27943 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:18.621618 27943 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:18.622351 27943 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:18.622542 27943 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:18.630424 27943 rpc_server.cc:307] RPC server started. Bound to: 127.27.73.254:36719
I20260812 06:19:18.630462 28055 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.73.254:36719 every 8 connection(s)
I20260812 06:19:18.632815 28057 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:18.638387 28057 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60: Bootstrap starting.
I20260812 06:19:18.640740 28057 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:18.641664 28057 log.cc:826] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:18.643414 28057 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60: No bootstrap required, opened a new log
I20260812 06:19:18.646149 28057 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1ee47099f01c480e9ffa1fe21ba3fa60" member_type: VOTER }
I20260812 06:19:18.646376 28057 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:18.646508 28057 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1ee47099f01c480e9ffa1fe21ba3fa60, State: Initialized, Role: FOLLOWER
I20260812 06:19:18.647119 28057 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1ee47099f01c480e9ffa1fe21ba3fa60" member_type: VOTER }
I20260812 06:19:18.647287 28057 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:18.647380 28057 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:18.647511 28057 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:18.648319 28057 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1ee47099f01c480e9ffa1fe21ba3fa60" member_type: VOTER }
I20260812 06:19:18.648772 28057 leader_election.cc:304] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: 1ee47099f01c480e9ffa1fe21ba3fa60; no voters: 
I20260812 06:19:18.649133 28057 leader_election.cc:290] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:18.649297 28061 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:18.649560 28061 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [term 1 LEADER]: Becoming Leader. State: Replica: 1ee47099f01c480e9ffa1fe21ba3fa60, State: Running, Role: LEADER
I20260812 06:19:18.649948 28061 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1ee47099f01c480e9ffa1fe21ba3fa60" member_type: VOTER }
I20260812 06:19:18.650182 28057 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:18.651999 28064 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1ee47099f01c480e9ffa1fe21ba3fa60. Latest consensus state: current_term: 1 leader_uuid: "1ee47099f01c480e9ffa1fe21ba3fa60" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1ee47099f01c480e9ffa1fe21ba3fa60" member_type: VOTER } }
I20260812 06:19:18.652046 28062 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1ee47099f01c480e9ffa1fe21ba3fa60" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1ee47099f01c480e9ffa1fe21ba3fa60" member_type: VOTER } }
I20260812 06:19:18.652149 28062 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:18.652149 28064 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:18.652699 28081 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:18.652701 27943 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:18.655040 28081 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:18.659816 28081 catalog_manager.cc:1383] Generated new cluster ID: 846b7c4cf4fd460a838a24f992cdd7df
I20260812 06:19:18.659885 28081 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:18.687812 28081 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:18.688743 28081 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:18.695871 28081 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60: Generated new TSK 0
I20260812 06:19:18.696532 28081 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:18.717491 27943 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:18.720180 28094 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:18.720259 28098 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:18.720346 28095 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:18.720636 27943 server_base.cc:1061] running on GCE node
I20260812 06:19:18.720803 27943 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:18.720849 27943 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:18.720871 27943 hybrid_clock.cc:648] HybridClock initialized: now 1786515558720871 us; error 0 us; skew 500 ppm
I20260812 06:19:18.721808 27943 webserver.cc:533] Webserver started at http://127.27.73.193:35083/ using document root <none> and password file <none>
I20260812 06:19:18.721973 27943 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:18.722031 27943 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:18.722105 27943 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:18.722602 27943 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/instance:
uuid: "a1ec195efaff4c67b4b5d9de64907444"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-jztv"
I20260812 06:19:18.724436 27943 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:18.725484 28105 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.725745 27943 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:18.725809 27943 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root
uuid: "a1ec195efaff4c67b4b5d9de64907444"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-jztv"
I20260812 06:19:18.725895 27943 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:18.731148 27943 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:18.731525 27943 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:18.731990 27943 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:18.732762 27943 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:18.732810 27943 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.732877 27943 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:18.732916 27943 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.739696 27943 rpc_server.cc:307] RPC server started. Bound to: 127.27.73.193:42215
I20260812 06:19:18.739900 28212 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.73.193:42215 every 8 connection(s)
I20260812 06:19:18.749313 28215 heartbeater.cc:344] Connected to a master server at 127.27.73.254:36719
I20260812 06:19:18.749538 28215 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:18.749949 28215 heartbeater.cc:507] Master 127.27.73.254:36719 requested a full tablet report, sending...
I20260812 06:19:18.751484 27998 ts_manager.cc:194] Registered new tserver with Master: a1ec195efaff4c67b4b5d9de64907444 (127.27.73.193:42215)
I20260812 06:19:18.751741 27943 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011344728s
I20260812 06:19:18.752996 27998 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54020
I20260812 06:19:18.760954 27998 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54026:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:18.775100 28157 tablet_service.cc:1511] Processing CreateTablet for tablet 98b1483b5ef5486b9970a8d242100087 (DEFAULT_TABLE table=heavy-update-compaction-test [id=f0190816ed884621a26922fdae07b6b5]), partition=
I20260812 06:19:18.775532 28157 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 98b1483b5ef5486b9970a8d242100087. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:18.777936 28234 tablet_bootstrap.cc:492] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Bootstrap starting.
I20260812 06:19:18.778935 28234 tablet_bootstrap.cc:654] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:18.780171 28234 tablet_bootstrap.cc:492] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: No bootstrap required, opened a new log
I20260812 06:19:18.780292 28234 ts_tablet_manager.cc:1403] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:18.780718 28234 raft_consensus.cc:359] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a1ec195efaff4c67b4b5d9de64907444" member_type: VOTER last_known_addr { host: "127.27.73.193" port: 42215 } }
I20260812 06:19:18.780838 28234 raft_consensus.cc:385] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:18.780885 28234 raft_consensus.cc:740] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a1ec195efaff4c67b4b5d9de64907444, State: Initialized, Role: FOLLOWER
I20260812 06:19:18.781020 28234 consensus_queue.cc:260] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444 [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a1ec195efaff4c67b4b5d9de64907444" member_type: VOTER last_known_addr { host: "127.27.73.193" port: 42215 } }
I20260812 06:19:18.781138 28234 raft_consensus.cc:399] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:18.781188 28234 raft_consensus.cc:493] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:18.781242 28234 raft_consensus.cc:3060] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:18.781942 28234 raft_consensus.cc:515] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a1ec195efaff4c67b4b5d9de64907444" member_type: VOTER last_known_addr { host: "127.27.73.193" port: 42215 } }
I20260812 06:19:18.782097 28234 leader_election.cc:304] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444 [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: a1ec195efaff4c67b4b5d9de64907444; no voters: 
I20260812 06:19:18.782336 28234 leader_election.cc:290] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:18.782469 28236 raft_consensus.cc:2804] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:18.782711 28236 raft_consensus.cc:697] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444 [term 1 LEADER]: Becoming Leader. State: Replica: a1ec195efaff4c67b4b5d9de64907444, State: Running, Role: LEADER
I20260812 06:19:18.782732 28234 ts_tablet_manager.cc:1434] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:18.782862 28236 consensus_queue.cc:237] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444 [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a1ec195efaff4c67b4b5d9de64907444" member_type: VOTER last_known_addr { host: "127.27.73.193" port: 42215 } }
I20260812 06:19:18.782990 28215 heartbeater.cc:499] Master 127.27.73.254:36719 was elected leader, sending a full tablet report...
I20260812 06:19:18.785502 27996 catalog_manager.cc:5719] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444 reported cstate change: term changed from 0 to 1, leader changed from <none> to a1ec195efaff4c67b4b5d9de64907444 (127.27.73.193). New cstate: current_term: 1 leader_uuid: "a1ec195efaff4c67b4b5d9de64907444" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a1ec195efaff4c67b4b5d9de64907444" member_type: VOTER last_known_addr { host: "127.27.73.193" port: 42215 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:18.858204 27943 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.066s	user 0.020s	sys 0.012s
I20260812 06:19:18.990839 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushMRSOp(98b1483b5ef5486b9970a8d242100087): perf score=19.054940
I20260812 06:19:19.173612 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushMRSOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.182s	user 0.136s	sys 0.040s Metrics: {"bytes_written":13415136,"cfile_init":1,"compiler_manager_pool.queue_time_us":200,"delete_count":0,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":874,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45895,"lbm_writes_lt_1ms":784,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":153472,"thread_start_us":135,"threads_started":1,"update_count":1635}
I20260812 06:19:19.174894 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=3.181125
I20260812 06:19:19.196094 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.021s	user 0.008s	sys 0.012s Metrics: {"bytes_written":4635975,"delete_count":0,"lbm_write_time_us":5969,"lbm_writes_lt_1ms":116,"reinsert_count":0,"update_count":565}
I20260812 06:19:19.196609 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling LogGCOp(98b1483b5ef5486b9970a8d242100087): free 20743880 bytes of WAL
I20260812 06:19:19.196899 28117 log_reader.cc:385] T 98b1483b5ef5486b9970a8d242100087: removed 2 log segments from log reader
I20260812 06:19:19.196972 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000001 (ops 1-6)
I20260812 06:19:19.197036 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000002 (ops 7-11)
I20260812 06:19:19.202535 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: LogGCOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:19:19.202912 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling UndoDeltaBlockGCOp(98b1483b5ef5486b9970a8d242100087): 16411394 bytes on disk
I20260812 06:19:19.203603 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: UndoDeltaBlockGCOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:19:19.204070 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=1.196750
I20260812 06:19:19.214808 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":2461654,"delete_count":0,"lbm_write_time_us":3769,"lbm_writes_lt_1ms":63,"reinsert_count":0,"update_count":300}
I20260812 06:19:19.215276 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:19.377660 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.162s	user 0.125s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774765,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":320,"lbm_read_time_us":11379,"lbm_reads_lt_1ms":569,"lbm_write_time_us":27654,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":346,"threads_started":5,"update_count":2500}
I20260812 06:19:19.378309 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=10.126437
I20260812 06:19:19.417541 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.039s	user 0.032s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17426,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:19.418084 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:19.431365 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4786,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.431792 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:19.569582 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.138s	user 0.105s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":943,"lbm_read_time_us":8681,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26669,"lbm_writes_lt_1ms":443,"mutex_wait_us":308,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":37120,"update_count":2000}
I20260812 06:19:19.570351 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=10.126437
I20260812 06:19:19.616153 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.046s	user 0.025s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14358,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:19.616603 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:19.626905 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3968,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.627323 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:19.749751 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.122s	user 0.098s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1138,"lbm_read_time_us":9747,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22731,"lbm_writes_lt_1ms":443,"mutex_wait_us":320,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:19:19.750403 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=10.126437
I20260812 06:19:19.796082 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.046s	user 0.026s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13928,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:19.796633 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:19.811815 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5586,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.812394 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:19.943873 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.131s	user 0.097s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":619,"lbm_read_time_us":8933,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25663,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":670976,"update_count":2000}
I20260812 06:19:19.944484 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=10.126437
I20260812 06:19:19.994920 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.050s	user 0.022s	sys 0.021s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15935,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:19.995393 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:20.005730 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4125,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.006166 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:20.156301 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.150s	user 0.102s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":977,"lbm_read_time_us":10879,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23109,"lbm_writes_lt_1ms":443,"mutex_wait_us":279,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24960,"update_count":2000}
I20260812 06:19:20.156843 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=10.126437
I20260812 06:19:20.195564 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.039s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14659,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:20.196130 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:20.207032 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4179,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.207542 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:20.336683 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.129s	user 0.090s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":733,"lbm_read_time_us":9665,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24187,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.337267 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=10.126437
I20260812 06:19:20.380719 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.043s	user 0.015s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16465,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:20.381176 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:20.391646 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3985,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.392336 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushMRSOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:20.425666 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushMRSOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":278,"dirs.run_wall_time_us":1513,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1668,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:20.426594 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling LogGCOp(98b1483b5ef5486b9970a8d242100087): free 120553341 bytes of WAL
I20260812 06:19:20.426823 28117 log_reader.cc:385] T 98b1483b5ef5486b9970a8d242100087: removed 12 log segments from log reader
I20260812 06:19:20.426893 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000003 (ops 12-16)
I20260812 06:19:20.426944 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000004 (ops 17-21)
I20260812 06:19:20.426978 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000005 (ops 22-26)
I20260812 06:19:20.427021 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000006 (ops 27-30)
I20260812 06:19:20.427054 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000007 (ops 31-35)
I20260812 06:19:20.427090 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000008 (ops 36-40)
I20260812 06:19:20.427131 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000009 (ops 41-44)
I20260812 06:19:20.427171 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000010 (ops 45-49)
I20260812 06:19:20.427210 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000011 (ops 50-54)
I20260812 06:19:20.427251 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000012 (ops 55-59)
I20260812 06:19:20.427290 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000013 (ops 60-64)
I20260812 06:19:20.427333 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000014 (ops 65-69)
I20260812 06:19:20.450882 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: LogGCOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:20.451274 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling UndoDeltaBlockGCOp(98b1483b5ef5486b9970a8d242100087): 462 bytes on disk
I20260812 06:19:20.451689 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: UndoDeltaBlockGCOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:20.452179 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=3.181125
I20260812 06:19:20.463774 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4553929,"delete_count":0,"lbm_write_time_us":4558,"lbm_writes_lt_1ms":114,"reinsert_count":0,"update_count":555}
I20260812 06:19:20.464244 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:20.473695 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":3412,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:19:20.474272 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:20.641556 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.167s	user 0.110s	sys 0.047s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877331,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":379,"lbm_read_time_us":10816,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32453,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:19:20.642196 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=14.095187
I20260812 06:19:20.693629 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.051s	user 0.027s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23365,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.694139 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:20.706108 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.012s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4590,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.706585 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:20.870484 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.164s	user 0.123s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":181,"lbm_read_time_us":10325,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31459,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:19:20.871040 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=14.095187
I20260812 06:19:20.919283 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.048s	user 0.014s	sys 0.032s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22564,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.919863 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:20.935024 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5726,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.935611 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:21.107683 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.172s	user 0.117s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":697,"lbm_read_time_us":11322,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30355,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":2500}
I20260812 06:19:21.108271 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=14.095187
I20260812 06:19:21.149358 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.041s	user 0.024s	sys 0.014s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18318,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.150049 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:21.296602 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.146s	user 0.074s	sys 0.064s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":944,"lbm_read_time_us":9685,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22804,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:19:21.297348 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=14.095187
I20260812 06:19:21.346074 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.049s	user 0.021s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20698,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.346619 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:21.371158 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.024s	user 0.009s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5835,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.371851 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:21.552477 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.180s	user 0.115s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":487,"lbm_read_time_us":12744,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29887,"lbm_writes_lt_1ms":543,"mutex_wait_us":58,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":2500}
I20260812 06:19:21.553020 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=14.095187
I20260812 06:19:21.606971 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.054s	user 0.026s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25736,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.607468 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:21.624732 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.017s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4745,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.625370 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:21.793907 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.168s	user 0.124s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":554,"lbm_read_time_us":10196,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30724,"lbm_writes_lt_1ms":543,"mutex_wait_us":158,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:21.794545 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=14.095187
I20260812 06:19:21.852352 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.058s	user 0.033s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27064,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.853012 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:21.865916 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4972,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.866461 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushMRSOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:21.896786 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushMRSOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":91,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":1596,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1518,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:21.897528 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling LogGCOp(98b1483b5ef5486b9970a8d242100087): free 124710305 bytes of WAL
I20260812 06:19:21.897771 28117 log_reader.cc:385] T 98b1483b5ef5486b9970a8d242100087: removed 12 log segments from log reader
I20260812 06:19:21.897821 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000015 (ops 70-74)
I20260812 06:19:21.897851 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000016 (ops 75-79)
I20260812 06:19:21.897897 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000017 (ops 80-84)
I20260812 06:19:21.897938 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000018 (ops 85-89)
I20260812 06:19:21.897966 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000019 (ops 90-94)
I20260812 06:19:21.898020 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000020 (ops 95-99)
I20260812 06:19:21.898062 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000021 (ops 100-104)
I20260812 06:19:21.898101 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000022 (ops 105-109)
I20260812 06:19:21.898160 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000023 (ops 110-114)
I20260812 06:19:21.898197 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000024 (ops 115-119)
I20260812 06:19:21.898262 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000025 (ops 120-124)
I20260812 06:19:21.898293 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000026 (ops 125-129)
I20260812 06:19:21.925851 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: LogGCOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.028s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:19:21.926389 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=6.157687
I20260812 06:19:21.956089 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.030s	user 0.019s	sys 0.004s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":10000,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:21.956671 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:22.177095 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.220s	user 0.179s	sys 0.040s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979632,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1346,"lbm_read_time_us":15852,"lbm_reads_lt_1ms":765,"lbm_write_time_us":37962,"lbm_writes_lt_1ms":743,"mutex_wait_us":839,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10880,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:19:22.177807 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling UndoDeltaBlockGCOp(98b1483b5ef5486b9970a8d242100087): 483 bytes on disk
I20260812 06:19:22.178372 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: UndoDeltaBlockGCOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":123,"lbm_reads_lt_1ms":4}
I20260812 06:19:22.179185 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=15.087375
I20260812 06:19:22.227941 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.049s	user 0.025s	sys 0.022s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":21431,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:22.228822 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:22.244899 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5495,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:22.245504 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:22.428265 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.183s	user 0.135s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":622,"lbm_read_time_us":12879,"lbm_reads_lt_1ms":568,"lbm_write_time_us":31163,"lbm_writes_lt_1ms":543,"mutex_wait_us":259,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:22.428916 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=14.095187
I20260812 06:19:22.494807 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.066s	user 0.025s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23193,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.495321 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:22.506373 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4415,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.506865 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:22.673094 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.166s	user 0.115s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":139,"lbm_read_time_us":12741,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27884,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:22.673692 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=11.118625
I20260812 06:19:22.709682 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.036s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15553,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:22.710994 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:22.729691 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.018s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6261,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:22.730166 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:22.885190 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.155s	user 0.103s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":220,"lbm_read_time_us":7544,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24209,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2000}
I20260812 06:19:22.885803 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=14.095187
I20260812 06:19:22.934481 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.048s	user 0.023s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17850,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.934994 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:22.946080 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3871,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.946751 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:23.104413 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.157s	user 0.092s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1072,"lbm_read_time_us":9969,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31291,"lbm_writes_lt_1ms":543,"mutex_wait_us":319,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:19:23.104939 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=14.095187
I20260812 06:19:23.153748 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.049s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21006,"lbm_writes_lt_1ms":403,"mutex_wait_us":2,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.154309 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:23.164953 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3825,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.165782 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:23.327193 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.161s	user 0.118s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":911,"lbm_read_time_us":11253,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29528,"lbm_writes_lt_1ms":543,"mutex_wait_us":318,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:19:23.327724 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=14.095187
I20260812 06:19:23.389261 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.061s	user 0.035s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":26012,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.389745 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=2.188937
I20260812 06:19:23.402114 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4260,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.402685 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushMRSOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:23.438206 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushMRSOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.035s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1474,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1515,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:23.439008 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling LogGCOp(98b1483b5ef5486b9970a8d242100087): free 132571642 bytes of WAL
I20260812 06:19:23.439270 28117 log_reader.cc:385] T 98b1483b5ef5486b9970a8d242100087: removed 13 log segments from log reader
I20260812 06:19:23.439317 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000027 (ops 130-134)
I20260812 06:19:23.439404 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000028 (ops 135-139)
I20260812 06:19:23.439458 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000029 (ops 140-144)
I20260812 06:19:23.439529 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000030 (ops 145-148)
I20260812 06:19:23.439579 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000031 (ops 149-153)
I20260812 06:19:23.439639 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000032 (ops 154-158)
I20260812 06:19:23.439687 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000033 (ops 159-163)
I20260812 06:19:23.439729 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000034 (ops 164-168)
I20260812 06:19:23.439774 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000035 (ops 169-173)
I20260812 06:19:23.439817 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000036 (ops 174-178)
I20260812 06:19:23.439862 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000037 (ops 179-183)
I20260812 06:19:23.439915 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000038 (ops 184-188)
I20260812 06:19:23.439961 28117 log.cc:1079] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/98b1483b5ef5486b9970a8d242100087/wal-000000039 (ops 189-192)
I20260812 06:19:23.471058 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: LogGCOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.032s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:19:23.471486 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=4.173312
I20260812 06:19:23.488225 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.017s	user 0.014s	sys 0.001s Metrics: {"bytes_written":6235917,"delete_count":0,"lbm_write_time_us":6926,"lbm_writes_lt_1ms":155,"reinsert_count":0,"update_count":760}
I20260812 06:19:23.488720 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:23.499233 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":1969352,"delete_count":0,"lbm_write_time_us":3219,"lbm_writes_lt_1ms":51,"reinsert_count":0,"update_count":240}
I20260812 06:19:23.499718 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087): perf score=1.000000
I20260812 06:19:23.628114 27943 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.770s	user 1.824s	sys 0.115s
I20260812 06:19:23.712253 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: MajorDeltaCompactionOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.212s	user 0.138s	sys 0.074s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979698,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":555,"lbm_read_time_us":16914,"lbm_reads_lt_1ms":762,"lbm_write_time_us":40079,"lbm_writes_lt_1ms":743,"mutex_wait_us":55,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:19:23.715507 28217 maintenance_manager.cc:419] P a1ec195efaff4c67b4b5d9de64907444: Scheduling FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087): perf score=10.126437
I20260812 06:19:23.727487 27943 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.099s	user 0.003s	sys 0.000s
I20260812 06:19:23.728101 27943 tablet_server.cc:179] TabletServer@127.27.73.193:0 shutting down...
I20260812 06:19:23.753571 28117 maintenance_manager.cc:643] P a1ec195efaff4c67b4b5d9de64907444: FlushDeltaMemStoresOp(98b1483b5ef5486b9970a8d242100087) complete. Timing: real 0.038s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16428,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:23.755154 27943 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:23.755591 27943 tablet_replica.cc:333] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444: stopping tablet replica
I20260812 06:19:23.755832 27943 raft_consensus.cc:2243] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:23.756069 27943 raft_consensus.cc:2272] T 98b1483b5ef5486b9970a8d242100087 P a1ec195efaff4c67b4b5d9de64907444 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:23.771013 27943 tablet_server.cc:196] TabletServer@127.27.73.193:0 shutdown complete.
I20260812 06:19:23.775818 27943 master.cc:562] Master@127.27.73.254:36719 shutting down...
I20260812 06:19:23.779505 27943 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:23.779661 27943 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:23.779714 27943 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1ee47099f01c480e9ffa1fe21ba3fa60: stopping tablet replica
I20260812 06:19:23.792135 27943 master.cc:584] Master@127.27.73.254:36719 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5292 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:23.878516 27943 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.73.254:39319
I20260812 06:19:23.878865 27943 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:23.880836 28268 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:23.880847 28270 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:23.880991 27943 server_base.cc:1061] running on GCE node
W20260812 06:19:23.880941 28273 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:23.881239 27943 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:23.881281 27943 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:23.881297 27943 hybrid_clock.cc:648] HybridClock initialized: now 1786515563881297 us; error 0 us; skew 500 ppm
I20260812 06:19:23.882305 27943 webserver.cc:533] Webserver started at http://127.27.73.254:36999/ using document root <none> and password file <none>
I20260812 06:19:23.882447 27943 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:23.882489 27943 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:23.882540 27943 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:23.882871 27943 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/master-0-root/instance:
uuid: "5278ca9a6744429a8bfb7650bcc79766"
format_stamp: "Formatted at 2026-08-12 06:19:23 on dist-test-slave-jztv"
I20260812 06:19:23.884284 27943 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:23.885115 28281 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:23.885383 27943 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:23.885453 27943 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/master-0-root
uuid: "5278ca9a6744429a8bfb7650bcc79766"
format_stamp: "Formatted at 2026-08-12 06:19:23 on dist-test-slave-jztv"
I20260812 06:19:23.885542 27943 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:23.891172 27943 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:23.891528 27943 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:23.895980 27943 rpc_server.cc:307] RPC server started. Bound to: 127.27.73.254:39319
I20260812 06:19:23.900846 28359 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.73.254:39319 every 8 connection(s)
I20260812 06:19:23.904474 28360 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:23.915104 28360 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766: Bootstrap starting.
I20260812 06:19:23.916007 28360 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:23.917124 28360 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766: No bootstrap required, opened a new log
I20260812 06:19:23.917539 28360 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5278ca9a6744429a8bfb7650bcc79766" member_type: VOTER }
I20260812 06:19:23.917672 28360 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:23.917723 28360 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5278ca9a6744429a8bfb7650bcc79766, State: Initialized, Role: FOLLOWER
I20260812 06:19:23.917907 28360 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5278ca9a6744429a8bfb7650bcc79766" member_type: VOTER }
I20260812 06:19:23.918021 28360 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:23.918071 28360 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:23.918128 28360 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:23.918865 28360 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5278ca9a6744429a8bfb7650bcc79766" member_type: VOTER }
I20260812 06:19:23.919018 28360 leader_election.cc:304] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: 5278ca9a6744429a8bfb7650bcc79766; no voters: 
I20260812 06:19:23.919236 28360 leader_election.cc:290] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:23.919423 28364 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:23.919710 28364 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [term 1 LEADER]: Becoming Leader. State: Replica: 5278ca9a6744429a8bfb7650bcc79766, State: Running, Role: LEADER
I20260812 06:19:23.919831 28360 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:23.919864 28364 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5278ca9a6744429a8bfb7650bcc79766" member_type: VOTER }
I20260812 06:19:23.920297 28366 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5278ca9a6744429a8bfb7650bcc79766" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5278ca9a6744429a8bfb7650bcc79766" member_type: VOTER } }
I20260812 06:19:23.920423 28366 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:23.920316 28367 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5278ca9a6744429a8bfb7650bcc79766. Latest consensus state: current_term: 1 leader_uuid: "5278ca9a6744429a8bfb7650bcc79766" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5278ca9a6744429a8bfb7650bcc79766" member_type: VOTER } }
I20260812 06:19:23.920564 28367 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:23.921034 28372 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:23.921713 28372 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:23.922016 27943 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:23.923787 28372 catalog_manager.cc:1383] Generated new cluster ID: 19af886d612d428da7f48cb3822a3c77
I20260812 06:19:23.923867 28372 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:23.936049 28372 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:23.936622 28372 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:23.941416 28372 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766: Generated new TSK 0
I20260812 06:19:23.941632 28372 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:23.954617 27943 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:23.956856 28392 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:23.956943 28391 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:23.956954 27943 server_base.cc:1061] running on GCE node
W20260812 06:19:23.957211 28394 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:23.957424 27943 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:23.957468 27943 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:23.957484 27943 hybrid_clock.cc:648] HybridClock initialized: now 1786515563957484 us; error 0 us; skew 500 ppm
I20260812 06:19:23.958379 27943 webserver.cc:533] Webserver started at http://127.27.73.193:33267/ using document root <none> and password file <none>
I20260812 06:19:23.958516 27943 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:23.958563 27943 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:23.958622 27943 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:23.958992 27943 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/instance:
uuid: "844b34ea28514f1b9045ee8f06f87b73"
format_stamp: "Formatted at 2026-08-12 06:19:23 on dist-test-slave-jztv"
I20260812 06:19:23.960521 27943 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:23.961423 28401 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:23.961642 27943 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:23.961706 27943 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root
uuid: "844b34ea28514f1b9045ee8f06f87b73"
format_stamp: "Formatted at 2026-08-12 06:19:23 on dist-test-slave-jztv"
I20260812 06:19:23.961763 27943 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:23.966629 27943 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:23.966893 27943 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:23.967133 27943 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:23.967796 27943 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:23.967839 27943 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:23.967917 27943 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:23.967955 27943 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:23.972230 27943 rpc_server.cc:307] RPC server started. Bound to: 127.27.73.193:39665
I20260812 06:19:23.972254 28502 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.73.193:39665 every 8 connection(s)
I20260812 06:19:23.977100 28503 heartbeater.cc:344] Connected to a master server at 127.27.73.254:39319
I20260812 06:19:23.977206 28503 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:23.977432 28503 heartbeater.cc:507] Master 127.27.73.254:39319 requested a full tablet report, sending...
I20260812 06:19:23.978076 28311 ts_manager.cc:194] Registered new tserver with Master: 844b34ea28514f1b9045ee8f06f87b73 (127.27.73.193:39665)
I20260812 06:19:23.978322 27943 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.005635379s
I20260812 06:19:23.979096 28311 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:43224
I20260812 06:19:23.985229 28311 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:43232:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:23.994274 28449 tablet_service.cc:1511] Processing CreateTablet for tablet 0d8516f4bbc946459522af63bce16646 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ec73f8ec1c164fe086878453b3fdd6cd]), partition=
I20260812 06:19:23.994531 28449 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 0d8516f4bbc946459522af63bce16646. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:23.996412 28524 tablet_bootstrap.cc:492] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Bootstrap starting.
I20260812 06:19:23.997360 28524 tablet_bootstrap.cc:654] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:23.998490 28524 tablet_bootstrap.cc:492] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: No bootstrap required, opened a new log
I20260812 06:19:23.998603 28524 ts_tablet_manager.cc:1403] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:23.999038 28524 raft_consensus.cc:359] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "844b34ea28514f1b9045ee8f06f87b73" member_type: VOTER last_known_addr { host: "127.27.73.193" port: 39665 } }
I20260812 06:19:23.999130 28524 raft_consensus.cc:385] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:23.999203 28524 raft_consensus.cc:740] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 844b34ea28514f1b9045ee8f06f87b73, State: Initialized, Role: FOLLOWER
I20260812 06:19:23.999413 28524 consensus_queue.cc:260] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73 [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "844b34ea28514f1b9045ee8f06f87b73" member_type: VOTER last_known_addr { host: "127.27.73.193" port: 39665 } }
I20260812 06:19:23.999492 28524 raft_consensus.cc:399] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:23.999563 28524 raft_consensus.cc:493] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:23.999619 28524 raft_consensus.cc:3060] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:24.000479 28524 raft_consensus.cc:515] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "844b34ea28514f1b9045ee8f06f87b73" member_type: VOTER last_known_addr { host: "127.27.73.193" port: 39665 } }
I20260812 06:19:24.000607 28524 leader_election.cc:304] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73 [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: 844b34ea28514f1b9045ee8f06f87b73; no voters: 
I20260812 06:19:24.000842 28524 leader_election.cc:290] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:24.000977 28528 raft_consensus.cc:2804] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:24.001165 28524 ts_tablet_manager.cc:1434] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:24.001185 28503 heartbeater.cc:499] Master 127.27.73.254:39319 was elected leader, sending a full tablet report...
I20260812 06:19:24.001227 28528 raft_consensus.cc:697] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73 [term 1 LEADER]: Becoming Leader. State: Replica: 844b34ea28514f1b9045ee8f06f87b73, State: Running, Role: LEADER
I20260812 06:19:24.001602 28528 consensus_queue.cc:237] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73 [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "844b34ea28514f1b9045ee8f06f87b73" member_type: VOTER last_known_addr { host: "127.27.73.193" port: 39665 } }
I20260812 06:19:24.002996 28311 catalog_manager.cc:5719] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73 reported cstate change: term changed from 0 to 1, leader changed from <none> to 844b34ea28514f1b9045ee8f06f87b73 (127.27.73.193). New cstate: current_term: 1 leader_uuid: "844b34ea28514f1b9045ee8f06f87b73" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "844b34ea28514f1b9045ee8f06f87b73" member_type: VOTER last_known_addr { host: "127.27.73.193" port: 39665 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:24.063395 27943 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.013s	sys 0.010s
I20260812 06:19:24.223172 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushMRSOp(0d8516f4bbc946459522af63bce16646): perf score=19.054940
I20260812 06:19:24.374370 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushMRSOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.151s	user 0.111s	sys 0.040s Metrics: {"bytes_written":12594664,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":98,"dirs.run_cpu_time_us":186,"dirs.run_wall_time_us":1111,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39013,"lbm_writes_lt_1ms":764,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":3968,"update_count":1535}
I20260812 06:19:24.375447 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling LogGCOp(0d8516f4bbc946459522af63bce16646): free 20743880 bytes of WAL
I20260812 06:19:24.375764 28411 log_reader.cc:385] T 0d8516f4bbc946459522af63bce16646: removed 2 log segments from log reader
I20260812 06:19:24.375883 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000001 (ops 1-6)
I20260812 06:19:24.375967 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000002 (ops 7-11)
I20260812 06:19:24.381561 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: LogGCOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:24.381991 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling UndoDeltaBlockGCOp(0d8516f4bbc946459522af63bce16646): 16411392 bytes on disk
I20260812 06:19:24.382488 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: UndoDeltaBlockGCOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:19:24.383157 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=3.181125
I20260812 06:19:24.407255 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.024s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4225735,"delete_count":0,"lbm_write_time_us":5217,"lbm_writes_lt_1ms":106,"reinsert_count":0,"update_count":515}
I20260812 06:19:24.407706 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:24.417196 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3573,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:24.417636 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:24.583612 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.166s	user 0.111s	sys 0.047s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774804,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":560,"lbm_read_time_us":11117,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29247,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":341,"threads_started":5,"update_count":2500}
I20260812 06:19:24.584236 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=14.095187
I20260812 06:19:24.630599 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.046s	user 0.036s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19139,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:24.631112 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:24.645891 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5526,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.646413 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:24.801424 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.155s	user 0.114s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":185,"lbm_read_time_us":9687,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31985,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:19:24.802626 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=11.118625
I20260812 06:19:24.837591 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.034s	user 0.014s	sys 0.017s Metrics: {"bytes_written":12717740,"delete_count":0,"lbm_write_time_us":14786,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:24.838271 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:24.853056 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5313,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:24.853698 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:24.987396 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.133s	user 0.106s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":213,"lbm_read_time_us":10765,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24761,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2000}
I20260812 06:19:24.988102 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=10.126437
I20260812 06:19:25.028877 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.041s	user 0.016s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13685,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.029436 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:25.040087 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.010s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4232,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.040550 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:25.185086 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.144s	user 0.108s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":309,"lbm_read_time_us":10475,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24369,"lbm_writes_lt_1ms":443,"mutex_wait_us":97,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2000}
I20260812 06:19:25.185673 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=10.126437
I20260812 06:19:25.231062 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.045s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13379,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.231521 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:25.242836 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4164,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.243413 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:25.367494 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.124s	user 0.108s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":814,"lbm_read_time_us":8359,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24795,"lbm_writes_lt_1ms":443,"mutex_wait_us":233,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":30080,"update_count":2000}
I20260812 06:19:25.368280 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=10.126437
I20260812 06:19:25.405942 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.037s	user 0.020s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15178,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.406453 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:25.417501 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4133,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.418093 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:25.549521 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.131s	user 0.105s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":952,"lbm_read_time_us":9541,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24944,"lbm_writes_lt_1ms":443,"mutex_wait_us":262,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2000}
I20260812 06:19:25.549985 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=10.126437
I20260812 06:19:25.585355 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.035s	user 0.019s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14319,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.586117 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushMRSOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:25.639526 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushMRSOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.053s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1514,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1569,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:25.640173 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling LogGCOp(0d8516f4bbc946459522af63bce16646): free 120553330 bytes of WAL
I20260812 06:19:25.640401 28411 log_reader.cc:385] T 0d8516f4bbc946459522af63bce16646: removed 12 log segments from log reader
I20260812 06:19:25.640453 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000003 (ops 12-16)
I20260812 06:19:25.640507 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000004 (ops 17-21)
I20260812 06:19:25.640550 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000005 (ops 22-26)
I20260812 06:19:25.640581 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000006 (ops 27-30)
I20260812 06:19:25.640621 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000007 (ops 31-35)
I20260812 06:19:25.640661 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000008 (ops 36-40)
I20260812 06:19:25.640699 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000009 (ops 41-45)
I20260812 06:19:25.640739 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000010 (ops 46-50)
I20260812 06:19:25.640779 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000011 (ops 51-55)
I20260812 06:19:25.640816 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000012 (ops 56-60)
I20260812 06:19:25.640861 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000013 (ops 61-64)
I20260812 06:19:25.640898 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000014 (ops 65-69)
I20260812 06:19:25.666577 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: LogGCOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:25.667109 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=6.157687
I20260812 06:19:25.693889 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.027s	user 0.016s	sys 0.009s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11755,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:25.694489 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling UndoDeltaBlockGCOp(0d8516f4bbc946459522af63bce16646): 472 bytes on disk
I20260812 06:19:25.694906 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: UndoDeltaBlockGCOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:19:25.695374 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:25.707978 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4454,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.708519 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:25.885759 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.177s	user 0.121s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":307,"lbm_read_time_us":11913,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33119,"lbm_writes_lt_1ms":643,"mutex_wait_us":18,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10240,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:19:25.886526 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=14.095187
I20260812 06:19:25.934036 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.047s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20020,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.934669 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:25.958066 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.023s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5245,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.958562 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:25.968632 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3903,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.969110 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:26.131800 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.163s	user 0.142s	sys 0.020s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":147,"lbm_read_time_us":11567,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33347,"lbm_writes_lt_1ms":643,"mutex_wait_us":38,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":3000}
I20260812 06:19:26.132771 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=14.095187
I20260812 06:19:26.178689 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.046s	user 0.025s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21307,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.179497 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:26.209129 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.029s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6150,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.209580 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:26.219692 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4015,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.220103 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:26.407079 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.187s	user 0.158s	sys 0.026s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":148,"lbm_read_time_us":12405,"lbm_reads_lt_1ms":673,"lbm_write_time_us":40169,"lbm_writes_lt_1ms":643,"mutex_wait_us":58,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":3000}
I20260812 06:19:26.407784 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=14.095187
I20260812 06:19:26.457479 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.049s	user 0.021s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23965,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.458091 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:26.469499 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4101,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.469988 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:26.624868 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.155s	user 0.106s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":236,"lbm_read_time_us":10098,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28422,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":75776,"update_count":2500}
I20260812 06:19:26.625646 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=14.095187
I20260812 06:19:26.688390 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.063s	user 0.028s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23292,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.688930 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:26.699280 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3827,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.700102 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:26.872066 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.172s	user 0.113s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1008,"lbm_read_time_us":10990,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30226,"lbm_writes_lt_1ms":543,"mutex_wait_us":282,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:19:26.872644 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=14.095187
I20260812 06:19:26.921545 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.049s	user 0.025s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18933,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.922142 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:26.932483 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4047,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.932979 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushMRSOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:26.965149 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushMRSOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.032s	user 0.020s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":200,"dirs.run_wall_time_us":1582,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1493,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:26.965826 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling LogGCOp(0d8516f4bbc946459522af63bce16646): free 120553380 bytes of WAL
I20260812 06:19:26.966095 28411 log_reader.cc:385] T 0d8516f4bbc946459522af63bce16646: removed 12 log segments from log reader
I20260812 06:19:26.966161 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000015 (ops 70-74)
I20260812 06:19:26.966200 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000016 (ops 75-79)
I20260812 06:19:26.966270 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000017 (ops 80-84)
I20260812 06:19:26.966293 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000018 (ops 85-89)
I20260812 06:19:26.966327 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000019 (ops 90-94)
I20260812 06:19:26.966358 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000020 (ops 95-98)
I20260812 06:19:26.966385 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000021 (ops 99-103)
I20260812 06:19:26.966415 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000022 (ops 104-108)
I20260812 06:19:26.966444 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000023 (ops 109-113)
I20260812 06:19:26.966470 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000024 (ops 114-118)
I20260812 06:19:26.966501 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000025 (ops 119-122)
I20260812 06:19:26.966534 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000026 (ops 123-127)
I20260812 06:19:26.993805 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: LogGCOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.028s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:26.994300 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:27.019546 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.025s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4198,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.019987 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:27.030109 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3969,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.030632 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling UndoDeltaBlockGCOp(0d8516f4bbc946459522af63bce16646): 462 bytes on disk
I20260812 06:19:27.031038 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: UndoDeltaBlockGCOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:19:27.031814 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:27.259577 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.228s	user 0.164s	sys 0.053s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":395,"lbm_read_time_us":16381,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39334,"lbm_writes_lt_1ms":743,"mutex_wait_us":390,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":35712,"thread_start_us":96,"threads_started":1,"update_count":3500}
I20260812 06:19:27.260267 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=18.063937
I20260812 06:19:27.316131 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.056s	user 0.022s	sys 0.032s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":24781,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:27.316882 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:27.336114 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.019s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5204,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.336889 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:27.505388 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.168s	user 0.132s	sys 0.035s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":949,"lbm_read_time_us":12049,"lbm_reads_lt_1ms":664,"lbm_write_time_us":35071,"lbm_writes_lt_1ms":643,"mutex_wait_us":68,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":3000}
I20260812 06:19:27.506130 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=14.095187
I20260812 06:19:27.568985 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.063s	user 0.039s	sys 0.021s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":27882,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.569546 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:27.593672 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.024s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5319,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.594200 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:27.605060 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4058,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.605594 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:27.764307 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.158s	user 0.130s	sys 0.028s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":200,"lbm_read_time_us":10112,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33623,"lbm_writes_lt_1ms":643,"mutex_wait_us":30,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":3000}
I20260812 06:19:27.765043 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=14.095187
I20260812 06:19:27.809010 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.044s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19546,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.809535 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:27.825922 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6382,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.826573 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:27.983150 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.156s	user 0.114s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":485,"lbm_read_time_us":9657,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30400,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:19:27.983805 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=14.095187
I20260812 06:19:28.032874 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.049s	user 0.022s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22787,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.033486 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:28.187119 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.153s	user 0.098s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":149,"lbm_read_time_us":10420,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22991,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:28.187831 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=14.095187
I20260812 06:19:28.240274 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.052s	user 0.018s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21435,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.240752 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:28.252610 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4093,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.253186 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushMRSOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:28.288944 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushMRSOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.036s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":181,"dirs.run_wall_time_us":1308,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2013,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:28.289754 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling LogGCOp(0d8516f4bbc946459522af63bce16646): free 116849819 bytes of WAL
I20260812 06:19:28.290010 28411 log_reader.cc:385] T 0d8516f4bbc946459522af63bce16646: removed 12 log segments from log reader
I20260812 06:19:28.290055 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000027 (ops 128-132)
I20260812 06:19:28.290107 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000028 (ops 133-137)
I20260812 06:19:28.290154 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000029 (ops 138-142)
I20260812 06:19:28.290194 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000030 (ops 143-146)
I20260812 06:19:28.290266 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000031 (ops 147-151)
I20260812 06:19:28.290305 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000032 (ops 152-156)
I20260812 06:19:28.290345 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000033 (ops 157-160)
I20260812 06:19:28.290382 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000034 (ops 161-165)
I20260812 06:19:28.290421 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000035 (ops 166-170)
I20260812 06:19:28.290457 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000036 (ops 171-174)
I20260812 06:19:28.290501 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000037 (ops 175-179)
I20260812 06:19:28.290541 28411 log.cc:1079] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: Deleting log segment in path: /tmp/dist-test-taskf25sgo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515558575838-27943-0/minicluster-data/ts-0-root/wals/0d8516f4bbc946459522af63bce16646/wal-000000038 (ops 180-184)
I20260812 06:19:28.313970 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: LogGCOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.024s	user 0.001s	sys 0.019s Metrics: {}
I20260812 06:19:28.314436 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:28.333258 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.019s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4466,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.333747 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling UndoDeltaBlockGCOp(0d8516f4bbc946459522af63bce16646): 447 bytes on disk
I20260812 06:19:28.334188 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: UndoDeltaBlockGCOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:28.334757 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:28.344997 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3960,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.345475 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:28.591885 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.246s	user 0.141s	sys 0.092s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979748,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":5479,"lbm_read_time_us":14939,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39546,"lbm_writes_lt_1ms":743,"mutex_wait_us":1698,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:19:28.592557 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=18.063937
I20260812 06:19:28.657855 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.065s	user 0.024s	sys 0.037s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":28758,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:28.658588 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646): perf score=2.188937
I20260812 06:19:28.669127 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: FlushDeltaMemStoresOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4184,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.669628 28504 maintenance_manager.cc:419] P 844b34ea28514f1b9045ee8f06f87b73: Scheduling MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646): perf score=1.000000
I20260812 06:19:28.698516 27943 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.635s	user 1.798s	sys 0.132s
I20260812 06:19:28.772565 27943 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.074s	user 0.000s	sys 0.000s
I20260812 06:19:28.773064 27943 tablet_server.cc:179] TabletServer@127.27.73.193:0 shutting down...
I20260812 06:19:28.844310 28411 maintenance_manager.cc:643] P 844b34ea28514f1b9045ee8f06f87b73: MajorDeltaCompactionOp(0d8516f4bbc946459522af63bce16646) complete. Timing: real 0.174s	user 0.126s	sys 0.048s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1435,"lbm_read_time_us":15686,"lbm_reads_lt_1ms":668,"lbm_write_time_us":28999,"lbm_writes_lt_1ms":643,"mutex_wait_us":375,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":3000}
I20260812 06:19:28.844902 27943 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:28.845163 27943 tablet_replica.cc:333] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73: stopping tablet replica
I20260812 06:19:28.845327 27943 raft_consensus.cc:2243] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:28.845523 27943 raft_consensus.cc:2272] T 0d8516f4bbc946459522af63bce16646 P 844b34ea28514f1b9045ee8f06f87b73 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:28.851725 27943 tablet_server.cc:196] TabletServer@127.27.73.193:0 shutdown complete.
I20260812 06:19:28.896979 27943 master.cc:562] Master@127.27.73.254:39319 shutting down...
I20260812 06:19:28.900614 27943 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:28.900781 27943 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:28.900831 27943 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5278ca9a6744429a8bfb7650bcc79766: stopping tablet replica
I20260812 06:19:28.913800 27943 master.cc:584] Master@127.27.73.254:39319 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5122 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10416 ms total)

[----------] Global test environment tear-down
[==========] 2 tests from 1 test suite ran. (10416 ms total)
[  PASSED  ] 2 tests.
