[==========] 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:17:54.858718 29305 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.158.126:41997
I20260812 06:17:54.859797 29305 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:17:54.860420 29305 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:54.866870 29310 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:17:54.866932 29305 server_base.cc:1061] running on GCE node
W20260812 06:17:54.866874 29311 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:17:54.867149 29313 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:17:54.867637 29305 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:54.867762 29305 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:17:54.867808 29305 hybrid_clock.cc:648] HybridClock initialized: now 1786515474867805 us; error 0 us; skew 500 ppm
I20260812 06:17:54.869666 29305 webserver.cc:533] Webserver started at http://127.28.158.126:35725/ using document root <none> and password file <none>
I20260812 06:17:54.870221 29305 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:54.870307 29305 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:54.870543 29305 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:54.872171 29305 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/master-0-root/instance:
uuid: "ec8df4985b4b42b0b67b45bee1e22841"
format_stamp: "Formatted at 2026-08-12 06:17:54 on dist-test-slave-10pc"
I20260812 06:17:54.875723 29305 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:17:54.877887 29318 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:17:54.878932 29305 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:54.879069 29305 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/master-0-root
uuid: "ec8df4985b4b42b0b67b45bee1e22841"
format_stamp: "Formatted at 2026-08-12 06:17:54 on dist-test-slave-10pc"
I20260812 06:17:54.879176 29305 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-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:17:54.897411 29305 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:54.898061 29305 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:17:54.898244 29305 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:54.906248 29305 rpc_server.cc:307] RPC server started. Bound to: 127.28.158.126:41997
I20260812 06:17:54.906252 29375 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.158.126:41997 every 8 connection(s)
I20260812 06:17:54.908675 29376 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:17:54.914554 29376 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841: Bootstrap starting.
I20260812 06:17:54.917119 29376 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:54.918113 29376 log.cc:826] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:54.919989 29376 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841: No bootstrap required, opened a new log
I20260812 06:17:54.922995 29376 raft_consensus.cc:359] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec8df4985b4b42b0b67b45bee1e22841" member_type: VOTER }
I20260812 06:17:54.923185 29376 raft_consensus.cc:385] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:54.923264 29376 raft_consensus.cc:740] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ec8df4985b4b42b0b67b45bee1e22841, State: Initialized, Role: FOLLOWER
I20260812 06:17:54.923946 29376 consensus_queue.cc:260] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [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: "ec8df4985b4b42b0b67b45bee1e22841" member_type: VOTER }
I20260812 06:17:54.924130 29376 raft_consensus.cc:399] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:54.924214 29376 raft_consensus.cc:493] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:54.924393 29376 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:54.925359 29376 raft_consensus.cc:515] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec8df4985b4b42b0b67b45bee1e22841" member_type: VOTER }
I20260812 06:17:54.925858 29376 leader_election.cc:304] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [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: ec8df4985b4b42b0b67b45bee1e22841; no voters: 
I20260812 06:17:54.926232 29376 leader_election.cc:290] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:54.926424 29379 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:54.926764 29379 raft_consensus.cc:697] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [term 1 LEADER]: Becoming Leader. State: Replica: ec8df4985b4b42b0b67b45bee1e22841, State: Running, Role: LEADER
I20260812 06:17:54.927155 29379 consensus_queue.cc:237] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [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: "ec8df4985b4b42b0b67b45bee1e22841" member_type: VOTER }
I20260812 06:17:54.927439 29376 sys_catalog.cc:565] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:54.929232 29382 sys_catalog.cc:455] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [sys.catalog]: SysCatalogTable state changed. Reason: New leader ec8df4985b4b42b0b67b45bee1e22841. Latest consensus state: current_term: 1 leader_uuid: "ec8df4985b4b42b0b67b45bee1e22841" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec8df4985b4b42b0b67b45bee1e22841" member_type: VOTER } }
I20260812 06:17:54.929278 29380 sys_catalog.cc:455] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ec8df4985b4b42b0b67b45bee1e22841" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec8df4985b4b42b0b67b45bee1e22841" member_type: VOTER } }
I20260812 06:17:54.929360 29382 sys_catalog.cc:458] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:54.929388 29380 sys_catalog.cc:458] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:54.930119 29305 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:54.932513 29396 catalog_manager.cc:1594] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:54.932580 29396 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:54.932672 29390 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:54.933637 29390 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:54.938421 29390 catalog_manager.cc:1383] Generated new cluster ID: 309e4d27f1954a0eb3ac49ac397219ec
I20260812 06:17:54.938491 29390 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:54.955780 29390 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:54.957059 29390 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:54.966650 29390 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841: Generated new TSK 0
I20260812 06:17:54.967516 29390 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:54.995296 29305 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:54.998241 29400 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:17:54.998274 29401 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:17:54.998551 29403 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:17:54.998637 29305 server_base.cc:1061] running on GCE node
I20260812 06:17:54.998802 29305 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:54.998857 29305 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:17:54.998872 29305 hybrid_clock.cc:648] HybridClock initialized: now 1786515474998873 us; error 0 us; skew 500 ppm
I20260812 06:17:54.999866 29305 webserver.cc:533] Webserver started at http://127.28.158.65:46261/ using document root <none> and password file <none>
I20260812 06:17:55.000037 29305 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:55.000100 29305 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:55.000202 29305 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:55.000692 29305 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/instance:
uuid: "1c845ae75b154748aa36c3e78b42b0fb"
format_stamp: "Formatted at 2026-08-12 06:17:54 on dist-test-slave-10pc"
I20260812 06:17:55.002250 29305 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:55.003334 29410 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:17:55.003664 29305 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:55.003757 29305 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root
uuid: "1c845ae75b154748aa36c3e78b42b0fb"
format_stamp: "Formatted at 2026-08-12 06:17:54 on dist-test-slave-10pc"
I20260812 06:17:55.003844 29305 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-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:17:55.020337 29305 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:55.020910 29305 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:55.021512 29305 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:55.022434 29305 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:55.022516 29305 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:55.022595 29305 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:55.022636 29305 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:55.029556 29305 rpc_server.cc:307] RPC server started. Bound to: 127.28.158.65:35667
I20260812 06:17:55.029593 29482 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.158.65:35667 every 8 connection(s)
I20260812 06:17:55.039847 29483 heartbeater.cc:344] Connected to a master server at 127.28.158.126:41997
I20260812 06:17:55.040129 29483 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:55.040671 29483 heartbeater.cc:507] Master 127.28.158.126:41997 requested a full tablet report, sending...
I20260812 06:17:55.042248 29338 ts_manager.cc:194] Registered new tserver with Master: 1c845ae75b154748aa36c3e78b42b0fb (127.28.158.65:35667)
I20260812 06:17:55.042662 29305 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012319811s
I20260812 06:17:55.043795 29338 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36924
I20260812 06:17:55.052721 29338 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36940:
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:17:55.067236 29442 tablet_service.cc:1511] Processing CreateTablet for tablet fd014d243bb54a559bdb9e44151e65a3 (DEFAULT_TABLE table=heavy-update-compaction-test [id=e0bb2a360472423d9dedc2e0558bb200]), partition=
I20260812 06:17:55.067746 29442 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet fd014d243bb54a559bdb9e44151e65a3. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:55.070207 29497 tablet_bootstrap.cc:492] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Bootstrap starting.
I20260812 06:17:55.071285 29497 tablet_bootstrap.cc:654] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:55.072690 29497 tablet_bootstrap.cc:492] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: No bootstrap required, opened a new log
I20260812 06:17:55.072817 29497 ts_tablet_manager.cc:1403] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:55.073274 29497 raft_consensus.cc:359] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c845ae75b154748aa36c3e78b42b0fb" member_type: VOTER last_known_addr { host: "127.28.158.65" port: 35667 } }
I20260812 06:17:55.073397 29497 raft_consensus.cc:385] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:55.073498 29497 raft_consensus.cc:740] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1c845ae75b154748aa36c3e78b42b0fb, State: Initialized, Role: FOLLOWER
I20260812 06:17:55.073665 29497 consensus_queue.cc:260] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb [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: "1c845ae75b154748aa36c3e78b42b0fb" member_type: VOTER last_known_addr { host: "127.28.158.65" port: 35667 } }
I20260812 06:17:55.073761 29497 raft_consensus.cc:399] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:55.073810 29497 raft_consensus.cc:493] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:55.073864 29497 raft_consensus.cc:3060] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:55.074631 29497 raft_consensus.cc:515] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c845ae75b154748aa36c3e78b42b0fb" member_type: VOTER last_known_addr { host: "127.28.158.65" port: 35667 } }
I20260812 06:17:55.074791 29497 leader_election.cc:304] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb [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: 1c845ae75b154748aa36c3e78b42b0fb; no voters: 
I20260812 06:17:55.075043 29497 leader_election.cc:290] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:55.075145 29500 raft_consensus.cc:2804] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:55.075393 29500 raft_consensus.cc:697] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb [term 1 LEADER]: Becoming Leader. State: Replica: 1c845ae75b154748aa36c3e78b42b0fb, State: Running, Role: LEADER
I20260812 06:17:55.075469 29497 ts_tablet_manager.cc:1434] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:55.075610 29500 consensus_queue.cc:237] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb [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: "1c845ae75b154748aa36c3e78b42b0fb" member_type: VOTER last_known_addr { host: "127.28.158.65" port: 35667 } }
I20260812 06:17:55.075924 29483 heartbeater.cc:499] Master 127.28.158.126:41997 was elected leader, sending a full tablet report...
I20260812 06:17:55.078284 29338 catalog_manager.cc:5719] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb reported cstate change: term changed from 0 to 1, leader changed from <none> to 1c845ae75b154748aa36c3e78b42b0fb (127.28.158.65). New cstate: current_term: 1 leader_uuid: "1c845ae75b154748aa36c3e78b42b0fb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c845ae75b154748aa36c3e78b42b0fb" member_type: VOTER last_known_addr { host: "127.28.158.65" port: 35667 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:55.146904 29305 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.019s	sys 0.008s
I20260812 06:17:55.280781 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushMRSOp(fd014d243bb54a559bdb9e44151e65a3): perf score=19.054940
I20260812 06:17:55.463289 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushMRSOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.182s	user 0.128s	sys 0.051s Metrics: {"bytes_written":12799773,"cfile_init":1,"compiler_manager_pool.queue_time_us":209,"delete_count":0,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":1059,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45498,"lbm_writes_lt_1ms":769,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":376320,"thread_start_us":141,"threads_started":1,"update_count":1560}
I20260812 06:17:55.464718 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling LogGCOp(fd014d243bb54a559bdb9e44151e65a3): free 20743880 bytes of WAL
I20260812 06:17:55.465108 29416 log_reader.cc:385] T fd014d243bb54a559bdb9e44151e65a3: removed 2 log segments from log reader
I20260812 06:17:55.465198 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000001 (ops 1-6)
I20260812 06:17:55.465286 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000002 (ops 7-11)
I20260812 06:17:55.471168 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: LogGCOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:17:55.471509 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling UndoDeltaBlockGCOp(fd014d243bb54a559bdb9e44151e65a3): 16411392 bytes on disk
I20260812 06:17:55.472070 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: UndoDeltaBlockGCOp(fd014d243bb54a559bdb9e44151e65a3) 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:17:55.472513 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=3.181125
I20260812 06:17:55.497503 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.025s	user 0.013s	sys 0.010s Metrics: {"bytes_written":4718026,"delete_count":0,"lbm_write_time_us":6381,"lbm_writes_lt_1ms":118,"reinsert_count":0,"update_count":575}
I20260812 06:17:55.498061 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.196750
I20260812 06:17:55.510869 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":2994980,"delete_count":0,"lbm_write_time_us":4820,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:17:55.511380 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:55.679167 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.168s	user 0.128s	sys 0.039s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774779,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1141,"lbm_read_time_us":12576,"lbm_reads_lt_1ms":569,"lbm_write_time_us":27419,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"thread_start_us":413,"threads_started":5,"update_count":2500}
I20260812 06:17:55.679754 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=10.126437
I20260812 06:17:55.726315 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.046s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":22891,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.726814 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:55.740897 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5269,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.741559 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:55.873385 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.132s	user 0.103s	sys 0.027s 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":519,"lbm_read_time_us":9544,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24641,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":30336,"update_count":2000}
I20260812 06:17:55.873816 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=10.126437
I20260812 06:17:55.920059 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.046s	user 0.016s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23508,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.920526 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:55.930820 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3986,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.931296 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:56.056591 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.125s	user 0.107s	sys 0.018s 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":421,"lbm_read_time_us":8954,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25752,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:56.057210 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=10.126437
I20260812 06:17:56.109581 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.052s	user 0.022s	sys 0.021s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21536,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.110102 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:56.121049 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3949,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.121582 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:56.245764 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.124s	user 0.071s	sys 0.052s 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":185,"lbm_read_time_us":9820,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23641,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2000}
I20260812 06:17:56.246356 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=10.126437
I20260812 06:17:56.303531 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.057s	user 0.019s	sys 0.022s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16553,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.304052 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:56.314932 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4196,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.315393 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:56.464774 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.149s	user 0.120s	sys 0.028s 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":775,"lbm_read_time_us":11081,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22066,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2000}
I20260812 06:17:56.465464 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=10.126437
I20260812 06:17:56.494169 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.029s	user 0.018s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12611,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.494804 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:56.507853 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4471,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.508291 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:56.632377 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.124s	user 0.104s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1237,"lbm_read_time_us":7868,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24006,"lbm_writes_lt_1ms":443,"mutex_wait_us":423,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2000}
I20260812 06:17:56.633237 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=10.126437
I20260812 06:17:56.667272 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.034s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14594,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.667907 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:56.688275 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.020s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5501,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.688794 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushMRSOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:56.740334 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushMRSOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.051s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":1601,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1688,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:56.741220 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling LogGCOp(fd014d243bb54a559bdb9e44151e65a3): free 112239272 bytes of WAL
I20260812 06:17:56.741434 29416 log_reader.cc:385] T fd014d243bb54a559bdb9e44151e65a3: removed 11 log segments from log reader
I20260812 06:17:56.741492 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000003 (ops 12-16)
I20260812 06:17:56.741544 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000004 (ops 17-21)
I20260812 06:17:56.741596 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000005 (ops 22-26)
I20260812 06:17:56.741636 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000006 (ops 27-30)
I20260812 06:17:56.741672 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000007 (ops 31-35)
I20260812 06:17:56.741709 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000008 (ops 36-40)
I20260812 06:17:56.741744 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000009 (ops 41-45)
I20260812 06:17:56.741781 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000010 (ops 46-50)
I20260812 06:17:56.741817 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000011 (ops 51-55)
I20260812 06:17:56.741853 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000012 (ops 56-60)
I20260812 06:17:56.741889 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000013 (ops 61-65)
I20260812 06:17:56.767601 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: LogGCOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:56.767972 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling UndoDeltaBlockGCOp(fd014d243bb54a559bdb9e44151e65a3): 472 bytes on disk
I20260812 06:17:56.768363 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: UndoDeltaBlockGCOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:17:56.768806 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=7.149875
I20260812 06:17:56.789943 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.021s	user 0.011s	sys 0.008s Metrics: {"bytes_written":8615325,"delete_count":0,"lbm_write_time_us":8794,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:56.790378 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling LogGCOp(fd014d243bb54a559bdb9e44151e65a3): free 8767174 bytes of WAL
I20260812 06:17:56.790571 29416 log_reader.cc:385] T fd014d243bb54a559bdb9e44151e65a3: removed 1 log segments from log reader
I20260812 06:17:56.790625 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000014 (ops 66-70)
I20260812 06:17:56.792410 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: LogGCOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:56.792812 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:56.809456 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.016s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4878,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:56.809895 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:56.995015 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.185s	user 0.152s	sys 0.032s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979744,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":468,"lbm_read_time_us":12615,"lbm_reads_lt_1ms":766,"lbm_write_time_us":40215,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:17:56.995898 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=15.087375
I20260812 06:17:57.035576 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.039s	user 0.024s	sys 0.012s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":17633,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:57.036096 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:57.058775 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.022s	user 0.012s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5771,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:57.059376 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:57.228930 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.169s	user 0.125s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774676,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":874,"lbm_read_time_us":10332,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26649,"lbm_writes_lt_1ms":543,"mutex_wait_us":281,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2500}
I20260812 06:17:57.229701 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=14.095187
I20260812 06:17:57.283838 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.054s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21473,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.284340 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:57.294562 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3819,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.294986 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:57.474280 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.179s	user 0.117s	sys 0.053s 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":1297,"lbm_read_time_us":11213,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33269,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":288,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:17:57.475056 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=11.118625
I20260812 06:17:57.508908 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.034s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":14744,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:57.512832 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:57.534076 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.021s	user 0.016s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":9492,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":450}
I20260812 06:17:57.534621 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:57.663455 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.129s	user 0.092s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":592,"lbm_read_time_us":8764,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25165,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:17:57.664271 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=10.126437
I20260812 06:17:57.697804 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.033s	user 0.014s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15253,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:57.698297 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:57.718566 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.020s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5759,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.719121 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:57.848939 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.130s	user 0.097s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":863,"lbm_read_time_us":9104,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25971,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2000}
I20260812 06:17:57.849581 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=10.126437
I20260812 06:17:57.903185 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.053s	user 0.023s	sys 0.024s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16354,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:57.903870 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:57.915952 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4677,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.916525 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:58.072068 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.155s	user 0.084s	sys 0.066s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":84,"lbm_read_time_us":8289,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26690,"lbm_writes_lt_1ms":443,"mutex_wait_us":35,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.072811 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=11.118625
I20260812 06:17:58.109190 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.036s	user 0.031s	sys 0.004s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15755,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:58.109771 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:58.121302 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4333,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:58.121778 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushMRSOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:58.150661 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushMRSOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.029s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1309,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1318,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:58.151369 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling LogGCOp(fd014d243bb54a559bdb9e44151e65a3): free 112239314 bytes of WAL
I20260812 06:17:58.151608 29416 log_reader.cc:385] T fd014d243bb54a559bdb9e44151e65a3: removed 11 log segments from log reader
I20260812 06:17:58.151656 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000015 (ops 71-75)
I20260812 06:17:58.151685 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000016 (ops 76-80)
I20260812 06:17:58.151750 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000017 (ops 81-85)
I20260812 06:17:58.151790 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000018 (ops 86-90)
I20260812 06:17:58.151834 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000019 (ops 91-95)
I20260812 06:17:58.151888 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000020 (ops 96-100)
I20260812 06:17:58.151932 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000021 (ops 101-105)
I20260812 06:17:58.151980 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000022 (ops 106-110)
I20260812 06:17:58.152021 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000023 (ops 111-114)
I20260812 06:17:58.152061 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000024 (ops 115-119)
I20260812 06:17:58.152101 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000025 (ops 120-124)
I20260812 06:17:58.176942 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: LogGCOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.025s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:58.177347 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling UndoDeltaBlockGCOp(fd014d243bb54a559bdb9e44151e65a3): 447 bytes on disk
I20260812 06:17:58.177920 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: UndoDeltaBlockGCOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:17:58.178630 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=5.165500
I20260812 06:17:58.204737 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.026s	user 0.017s	sys 0.009s Metrics: {"bytes_written":6358990,"delete_count":0,"lbm_write_time_us":6417,"lbm_writes_lt_1ms":158,"reinsert_count":0,"update_count":775}
I20260812 06:17:58.205555 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling LogGCOp(fd014d243bb54a559bdb9e44151e65a3): free 11564877 bytes of WAL
I20260812 06:17:58.205862 29416 log_reader.cc:385] T fd014d243bb54a559bdb9e44151e65a3: removed 1 log segments from log reader
I20260812 06:17:58.205950 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000026 (ops 125-128)
I20260812 06:17:58.209178 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: LogGCOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:58.211452 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:58.221279 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":1846277,"delete_count":0,"lbm_write_time_us":2880,"lbm_writes_lt_1ms":48,"reinsert_count":0,"update_count":225}
I20260812 06:17:58.221684 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:58.429365 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.208s	user 0.134s	sys 0.072s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877275,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":426,"lbm_read_time_us":13901,"lbm_reads_lt_1ms":670,"lbm_write_time_us":33690,"lbm_writes_lt_1ms":643,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":105,"threads_started":1,"update_count":3000}
I20260812 06:17:58.429980 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=14.095187
I20260812 06:17:58.483234 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.053s	user 0.035s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18477,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.483829 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:58.499596 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.016s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4152,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.500136 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:58.667492 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.167s	user 0.104s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1188,"lbm_read_time_us":12343,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26907,"lbm_writes_lt_1ms":543,"mutex_wait_us":310,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:17:58.668015 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=14.095187
I20260812 06:17:58.723456 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.055s	user 0.036s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25546,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.724009 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:58.748848 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.025s	user 0.009s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6209,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.749467 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:58.926802 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.177s	user 0.121s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":150,"lbm_read_time_us":12585,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31489,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:17:58.927489 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=14.095187
I20260812 06:17:58.975922 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.048s	user 0.024s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20015,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.976444 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:58.992357 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6049,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.992959 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:59.153903 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.161s	user 0.116s	sys 0.042s 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":204,"lbm_read_time_us":10570,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30589,"lbm_writes_lt_1ms":543,"mutex_wait_us":18,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:17:59.154723 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=11.118625
I20260812 06:17:59.184993 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.030s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":13055,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:59.185516 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:59.204562 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.019s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5940,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:59.205344 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:59.347059 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.142s	user 0.108s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":408,"lbm_read_time_us":8770,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27813,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:59.348073 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=10.126437
I20260812 06:17:59.386758 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.038s	user 0.016s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16141,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:59.387264 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:59.397985 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3829,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.398495 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:59.526659 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.128s	user 0.104s	sys 0.023s 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":224,"lbm_read_time_us":9338,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25141,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:17:59.527308 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=10.126437
I20260812 06:17:59.579177 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.052s	user 0.014s	sys 0.035s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16248,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:59.579802 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:59.596252 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6047,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.596836 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushMRSOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:59.633344 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushMRSOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.036s	user 0.027s	sys 0.005s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":1544,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1726,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:59.634066 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling LogGCOp(fd014d243bb54a559bdb9e44151e65a3): free 116396718 bytes of WAL
I20260812 06:17:59.634285 29416 log_reader.cc:385] T fd014d243bb54a559bdb9e44151e65a3: removed 12 log segments from log reader
I20260812 06:17:59.634333 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000027 (ops 129-133)
I20260812 06:17:59.634363 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000028 (ops 134-138)
I20260812 06:17:59.634423 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000029 (ops 139-142)
I20260812 06:17:59.634451 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000030 (ops 143-147)
I20260812 06:17:59.634490 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000031 (ops 148-152)
I20260812 06:17:59.634539 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000032 (ops 153-156)
I20260812 06:17:59.634579 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000033 (ops 157-161)
I20260812 06:17:59.634617 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000034 (ops 162-166)
I20260812 06:17:59.634657 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000035 (ops 167-170)
I20260812 06:17:59.634696 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000036 (ops 171-175)
I20260812 06:17:59.634735 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000037 (ops 176-180)
I20260812 06:17:59.634774 29416 log.cc:1079] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/fd014d243bb54a559bdb9e44151e65a3/wal-000000038 (ops 181-184)
I20260812 06:17:59.661504 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: LogGCOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:59.661968 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:59.681607 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.019s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4314,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.682034 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling UndoDeltaBlockGCOp(fd014d243bb54a559bdb9e44151e65a3): 462 bytes on disk
I20260812 06:17:59.682415 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: UndoDeltaBlockGCOp(fd014d243bb54a559bdb9e44151e65a3) 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:17:59.682989 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:59.693442 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3980,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.694096 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:17:59.893873 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.200s	user 0.148s	sys 0.051s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877340,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":211,"lbm_read_time_us":12654,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34943,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:17:59.894778 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=14.095187
I20260812 06:17:59.949747 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.055s	user 0.033s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27284,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.950325 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:59.971303 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.021s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5626,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.971765 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3): perf score=2.188937
I20260812 06:17:59.982041 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: FlushDeltaMemStoresOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3841,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.982479 29485 maintenance_manager.cc:419] P 1c845ae75b154748aa36c3e78b42b0fb: Scheduling MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3): perf score=1.000000
I20260812 06:18:00.016124 29305 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.869s	user 1.724s	sys 0.165s
I20260812 06:18:00.089205 29305 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.072s	user 0.005s	sys 0.000s
I20260812 06:18:00.089977 29305 tablet_server.cc:179] TabletServer@127.28.158.65:0 shutting down...
I20260812 06:18:00.151824 29416 maintenance_manager.cc:643] P 1c845ae75b154748aa36c3e78b42b0fb: MajorDeltaCompactionOp(fd014d243bb54a559bdb9e44151e65a3) complete. Timing: real 0.169s	user 0.112s	sys 0.056s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877221,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":365,"lbm_read_time_us":13989,"lbm_reads_lt_1ms":669,"lbm_write_time_us":29618,"lbm_writes_lt_1ms":643,"mutex_wait_us":38,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":3000}
I20260812 06:18:00.152968 29305 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:00.153419 29305 tablet_replica.cc:333] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb: stopping tablet replica
I20260812 06:18:00.153692 29305 raft_consensus.cc:2243] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:00.153940 29305 raft_consensus.cc:2272] T fd014d243bb54a559bdb9e44151e65a3 P 1c845ae75b154748aa36c3e78b42b0fb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:00.171104 29305 tablet_server.cc:196] TabletServer@127.28.158.65:0 shutdown complete.
I20260812 06:18:00.206923 29305 master.cc:562] Master@127.28.158.126:41997 shutting down...
I20260812 06:18:00.210677 29305 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:00.210901 29305 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:00.210997 29305 tablet_replica.cc:333] T 00000000000000000000000000000000 P ec8df4985b4b42b0b67b45bee1e22841: stopping tablet replica
I20260812 06:18:00.223606 29305 master.cc:584] Master@127.28.158.126:41997 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5458 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:00.317001 29305 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.158.126:34485
I20260812 06:18:00.317500 29305 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:00.319865 29525 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:18:00.320024 29522 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:18:00.320056 29305 server_base.cc:1061] running on GCE node
W20260812 06:18:00.319998 29521 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:18:00.320336 29305 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:00.320386 29305 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:18:00.320401 29305 hybrid_clock.cc:648] HybridClock initialized: now 1786515480320402 us; error 0 us; skew 500 ppm
I20260812 06:18:00.321334 29305 webserver.cc:533] Webserver started at http://127.28.158.126:41937/ using document root <none> and password file <none>
I20260812 06:18:00.321527 29305 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:00.321606 29305 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:00.321691 29305 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:00.322110 29305 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/master-0-root/instance:
uuid: "f95c114dd5af4b01b5e3141eb4602557"
format_stamp: "Formatted at 2026-08-12 06:18:00 on dist-test-slave-10pc"
I20260812 06:18:00.323668 29305 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:00.324687 29533 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:18:00.324913 29305 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:00.325014 29305 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/master-0-root
uuid: "f95c114dd5af4b01b5e3141eb4602557"
format_stamp: "Formatted at 2026-08-12 06:18:00 on dist-test-slave-10pc"
I20260812 06:18:00.325105 29305 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-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:18:00.338321 29305 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:00.338768 29305 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:00.343305 29305 rpc_server.cc:307] RPC server started. Bound to: 127.28.158.126:34485
I20260812 06:18:00.345466 29588 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.158.126:34485 every 8 connection(s)
I20260812 06:18:00.345613 29590 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:18:00.354775 29590 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557: Bootstrap starting.
I20260812 06:18:00.355567 29590 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:00.356696 29590 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557: No bootstrap required, opened a new log
I20260812 06:18:00.357060 29590 raft_consensus.cc:359] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f95c114dd5af4b01b5e3141eb4602557" member_type: VOTER }
I20260812 06:18:00.357156 29590 raft_consensus.cc:385] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:00.357179 29590 raft_consensus.cc:740] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f95c114dd5af4b01b5e3141eb4602557, State: Initialized, Role: FOLLOWER
I20260812 06:18:00.357283 29590 consensus_queue.cc:260] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [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: "f95c114dd5af4b01b5e3141eb4602557" member_type: VOTER }
I20260812 06:18:00.357342 29590 raft_consensus.cc:399] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:00.357364 29590 raft_consensus.cc:493] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:00.357609 29590 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:00.358443 29590 raft_consensus.cc:515] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f95c114dd5af4b01b5e3141eb4602557" member_type: VOTER }
I20260812 06:18:00.358603 29590 leader_election.cc:304] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [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: f95c114dd5af4b01b5e3141eb4602557; no voters: 
I20260812 06:18:00.358829 29590 leader_election.cc:290] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:00.359018 29593 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:00.359211 29593 raft_consensus.cc:697] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [term 1 LEADER]: Becoming Leader. State: Replica: f95c114dd5af4b01b5e3141eb4602557, State: Running, Role: LEADER
I20260812 06:18:00.359350 29590 sys_catalog.cc:565] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:00.359362 29593 consensus_queue.cc:237] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [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: "f95c114dd5af4b01b5e3141eb4602557" member_type: VOTER }
I20260812 06:18:00.359870 29595 sys_catalog.cc:455] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [sys.catalog]: SysCatalogTable state changed. Reason: New leader f95c114dd5af4b01b5e3141eb4602557. Latest consensus state: current_term: 1 leader_uuid: "f95c114dd5af4b01b5e3141eb4602557" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f95c114dd5af4b01b5e3141eb4602557" member_type: VOTER } }
I20260812 06:18:00.359854 29594 sys_catalog.cc:455] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f95c114dd5af4b01b5e3141eb4602557" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f95c114dd5af4b01b5e3141eb4602557" member_type: VOTER } }
I20260812 06:18:00.359972 29595 sys_catalog.cc:458] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:00.359982 29594 sys_catalog.cc:458] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:00.360280 29598 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:00.361155 29598 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:00.361343 29305 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:00.362920 29598 catalog_manager.cc:1383] Generated new cluster ID: 2d39eec935c04a5ea96263b4c1f05a17
I20260812 06:18:00.362982 29598 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:00.370662 29598 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:00.371178 29598 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:00.381731 29598 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557: Generated new TSK 0
I20260812 06:18:00.381922 29598 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:00.393667 29305 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:00.395623 29618 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:18:00.395646 29615 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:18:00.395699 29616 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:18:00.396014 29305 server_base.cc:1061] running on GCE node
I20260812 06:18:00.396157 29305 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:00.396191 29305 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:18:00.396206 29305 hybrid_clock.cc:648] HybridClock initialized: now 1786515480396206 us; error 0 us; skew 500 ppm
I20260812 06:18:00.397068 29305 webserver.cc:533] Webserver started at http://127.28.158.65:34731/ using document root <none> and password file <none>
I20260812 06:18:00.397202 29305 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:00.397243 29305 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:00.397298 29305 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:00.397642 29305 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/instance:
uuid: "21ea01bc35c34b39928c1c174080a682"
format_stamp: "Formatted at 2026-08-12 06:18:00 on dist-test-slave-10pc"
I20260812 06:18:00.399080 29305 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:00.399897 29623 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:18:00.400108 29305 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:00.400170 29305 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root
uuid: "21ea01bc35c34b39928c1c174080a682"
format_stamp: "Formatted at 2026-08-12 06:18:00 on dist-test-slave-10pc"
I20260812 06:18:00.400262 29305 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-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:18:00.420120 29305 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:00.420632 29305 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:00.421126 29305 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:00.421715 29305 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:00.421756 29305 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:00.421818 29305 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:00.421861 29305 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:00.426453 29305 rpc_server.cc:307] RPC server started. Bound to: 127.28.158.65:45777
I20260812 06:18:00.426496 29693 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.158.65:45777 every 8 connection(s)
I20260812 06:18:00.437548 29694 heartbeater.cc:344] Connected to a master server at 127.28.158.126:34485
I20260812 06:18:00.437680 29694 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:00.437968 29694 heartbeater.cc:507] Master 127.28.158.126:34485 requested a full tablet report, sending...
I20260812 06:18:00.438658 29550 ts_manager.cc:194] Registered new tserver with Master: 21ea01bc35c34b39928c1c174080a682 (127.28.158.65:45777)
I20260812 06:18:00.439075 29305 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012183138s
I20260812 06:18:00.439469 29550 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:43834
I20260812 06:18:00.446982 29550 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:43846:
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:18:00.455791 29652 tablet_service.cc:1511] Processing CreateTablet for tablet 89e4808e4c1e43efa239214830d18791 (DEFAULT_TABLE table=heavy-update-compaction-test [id=32d97fd21d924f11a9c57beff7bf64e6]), partition=
I20260812 06:18:00.456101 29652 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 89e4808e4c1e43efa239214830d18791. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:00.458348 29707 tablet_bootstrap.cc:492] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Bootstrap starting.
I20260812 06:18:00.459233 29707 tablet_bootstrap.cc:654] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:00.460376 29707 tablet_bootstrap.cc:492] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: No bootstrap required, opened a new log
I20260812 06:18:00.460489 29707 ts_tablet_manager.cc:1403] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:00.461066 29707 raft_consensus.cc:359] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "21ea01bc35c34b39928c1c174080a682" member_type: VOTER last_known_addr { host: "127.28.158.65" port: 45777 } }
I20260812 06:18:00.461184 29707 raft_consensus.cc:385] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:00.461221 29707 raft_consensus.cc:740] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 21ea01bc35c34b39928c1c174080a682, State: Initialized, Role: FOLLOWER
I20260812 06:18:00.461360 29707 consensus_queue.cc:260] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682 [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: "21ea01bc35c34b39928c1c174080a682" member_type: VOTER last_known_addr { host: "127.28.158.65" port: 45777 } }
I20260812 06:18:00.461464 29707 raft_consensus.cc:399] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:00.461520 29707 raft_consensus.cc:493] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:00.461585 29707 raft_consensus.cc:3060] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:00.462304 29707 raft_consensus.cc:515] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "21ea01bc35c34b39928c1c174080a682" member_type: VOTER last_known_addr { host: "127.28.158.65" port: 45777 } }
I20260812 06:18:00.462461 29707 leader_election.cc:304] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682 [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: 21ea01bc35c34b39928c1c174080a682; no voters: 
I20260812 06:18:00.462707 29707 leader_election.cc:290] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:00.462834 29709 raft_consensus.cc:2804] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:00.463066 29694 heartbeater.cc:499] Master 127.28.158.126:34485 was elected leader, sending a full tablet report...
I20260812 06:18:00.463109 29709 raft_consensus.cc:697] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682 [term 1 LEADER]: Becoming Leader. State: Replica: 21ea01bc35c34b39928c1c174080a682, State: Running, Role: LEADER
I20260812 06:18:00.463068 29707 ts_tablet_manager.cc:1434] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Time spent starting tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:00.463239 29709 consensus_queue.cc:237] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682 [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: "21ea01bc35c34b39928c1c174080a682" member_type: VOTER last_known_addr { host: "127.28.158.65" port: 45777 } }
I20260812 06:18:00.464607 29550 catalog_manager.cc:5719] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682 reported cstate change: term changed from 0 to 1, leader changed from <none> to 21ea01bc35c34b39928c1c174080a682 (127.28.158.65). New cstate: current_term: 1 leader_uuid: "21ea01bc35c34b39928c1c174080a682" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "21ea01bc35c34b39928c1c174080a682" member_type: VOTER last_known_addr { host: "127.28.158.65" port: 45777 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:00.524852 29305 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.013s	sys 0.010s
I20260812 06:18:00.677409 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushMRSOp(89e4808e4c1e43efa239214830d18791): perf score=19.054940
I20260812 06:18:00.827173 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushMRSOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.149s	user 0.103s	sys 0.044s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":721,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37790,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:00.827881 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling LogGCOp(89e4808e4c1e43efa239214830d18791): free 20743880 bytes of WAL
I20260812 06:18:00.828135 29628 log_reader.cc:385] T 89e4808e4c1e43efa239214830d18791: removed 2 log segments from log reader
I20260812 06:18:00.828197 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000001 (ops 1-6)
I20260812 06:18:00.828239 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000002 (ops 7-11)
I20260812 06:18:00.834105 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: LogGCOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:00.834501 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling UndoDeltaBlockGCOp(89e4808e4c1e43efa239214830d18791): 16411396 bytes on disk
I20260812 06:18:00.835003 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: UndoDeltaBlockGCOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:18:00.835541 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:00.852308 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6271,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.852799 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:01.012930 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.160s	user 0.127s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":477,"lbm_read_time_us":11766,"lbm_reads_lt_1ms":460,"lbm_write_time_us":28060,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":378,"threads_started":5,"update_count":2000}
I20260812 06:18:01.013541 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=11.118625
I20260812 06:18:01.062086 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.048s	user 0.035s	sys 0.012s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15811,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:01.062752 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:01.081118 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.018s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3869,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:01.081584 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:01.239086 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.157s	user 0.099s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":171,"lbm_read_time_us":10903,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22609,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23168,"update_count":2000}
I20260812 06:18:01.239753 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=14.095187
I20260812 06:18:01.294720 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.055s	user 0.028s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25738,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.295250 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:01.307790 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4335,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.308496 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:01.502254 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.193s	user 0.152s	sys 0.037s 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":1056,"lbm_read_time_us":12998,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28061,"lbm_writes_lt_1ms":543,"mutex_wait_us":235,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:18:01.503033 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=14.095187
I20260812 06:18:01.557209 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.054s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26151,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.557786 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:01.569968 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4651,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.570485 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:01.723099 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.152s	user 0.109s	sys 0.038s 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":745,"lbm_read_time_us":8704,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28182,"lbm_writes_lt_1ms":543,"mutex_wait_us":312,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:18:01.723726 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=14.095187
I20260812 06:18:01.779188 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.055s	user 0.037s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24373,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.779755 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:01.796379 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6289,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.797197 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:01.954062 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.157s	user 0.132s	sys 0.016s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":652,"lbm_read_time_us":9269,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29759,"lbm_writes_lt_1ms":543,"mutex_wait_us":292,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:18:01.954566 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=14.095187
I20260812 06:18:02.009060 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.054s	user 0.034s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22138,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":179584,"update_count":2000}
I20260812 06:18:02.009688 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:02.021230 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4128,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.021740 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushMRSOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:02.052779 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushMRSOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.031s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":88,"dirs.run_cpu_time_us":267,"dirs.run_wall_time_us":1528,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1989,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:02.053455 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling LogGCOp(89e4808e4c1e43efa239214830d18791): free 111786258 bytes of WAL
I20260812 06:18:02.053722 29628 log_reader.cc:385] T 89e4808e4c1e43efa239214830d18791: removed 11 log segments from log reader
I20260812 06:18:02.053788 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000003 (ops 12-16)
I20260812 06:18:02.053841 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000004 (ops 17-21)
I20260812 06:18:02.053900 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000005 (ops 22-26)
I20260812 06:18:02.053941 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000006 (ops 27-31)
I20260812 06:18:02.053979 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000007 (ops 32-36)
I20260812 06:18:02.054016 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000008 (ops 37-40)
I20260812 06:18:02.054052 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000009 (ops 41-45)
I20260812 06:18:02.054121 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000010 (ops 46-50)
I20260812 06:18:02.054180 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000011 (ops 51-55)
I20260812 06:18:02.054219 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000012 (ops 56-60)
I20260812 06:18:02.054255 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000013 (ops 61-64)
I20260812 06:18:02.079998 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: LogGCOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:02.080523 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling UndoDeltaBlockGCOp(89e4808e4c1e43efa239214830d18791): 448 bytes on disk
I20260812 06:18:02.080962 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: UndoDeltaBlockGCOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:18:02.081418 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:02.095747 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.014s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4067,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.096153 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:02.106833 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.107271 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:02.363737 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.256s	user 0.175s	sys 0.069s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":574,"lbm_read_time_us":15849,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43032,"lbm_writes_lt_1ms":743,"mutex_wait_us":25,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":90,"threads_started":1,"update_count":3500}
I20260812 06:18:02.364524 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=18.063937
I20260812 06:18:02.466010 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.101s	user 0.025s	sys 0.030s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":71198,"lbm_writes_1-10_ms":1,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:18:02.466658 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:02.485527 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.019s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6044,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.485988 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:02.697430 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.211s	user 0.123s	sys 0.083s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1080,"lbm_read_time_us":13380,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34547,"lbm_writes_lt_1ms":643,"mutex_wait_us":52,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":3000}
I20260812 06:18:02.698196 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=18.063937
I20260812 06:18:02.766618 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.068s	user 0.025s	sys 0.040s Metrics: {"bytes_written":20512358,"delete_count":0,"lbm_write_time_us":30394,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:02.767129 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:02.778407 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4015,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.779124 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:02.987787 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.208s	user 0.117s	sys 0.088s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877145,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":769,"lbm_read_time_us":15102,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34441,"lbm_writes_lt_1ms":643,"mutex_wait_us":309,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":3000}
I20260812 06:18:02.988337 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=15.087375
I20260812 06:18:03.042390 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.054s	user 0.020s	sys 0.032s Metrics: {"bytes_written":16820141,"delete_count":0,"lbm_write_time_us":23885,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:03.042938 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:03.062093 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.019s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4727,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.062569 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:03.072806 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3936,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:03.073316 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:03.299787 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.226s	user 0.162s	sys 0.056s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1275,"lbm_read_time_us":15378,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36833,"lbm_writes_lt_1ms":643,"mutex_wait_us":398,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":3000}
I20260812 06:18:03.300592 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=18.063937
I20260812 06:18:03.378772 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.078s	user 0.044s	sys 0.021s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":30054,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:03.379323 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:03.390348 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.391093 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:03.588181 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.197s	user 0.137s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1139,"lbm_read_time_us":14372,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33356,"lbm_writes_lt_1ms":643,"mutex_wait_us":455,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":3000}
I20260812 06:18:03.589051 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=14.095187
I20260812 06:18:03.650162 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.061s	user 0.017s	sys 0.041s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26905,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:03.650653 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:03.678655 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.028s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6733,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.679162 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:03.690379 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4323,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.690894 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushMRSOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:03.724337 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushMRSOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":263,"dirs.run_wall_time_us":1668,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1923,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:03.725159 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling LogGCOp(89e4808e4c1e43efa239214830d18791): free 129320447 bytes of WAL
I20260812 06:18:03.725418 29628 log_reader.cc:385] T 89e4808e4c1e43efa239214830d18791: removed 13 log segments from log reader
I20260812 06:18:03.725466 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000014 (ops 65-69)
I20260812 06:18:03.725525 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000015 (ops 70-74)
I20260812 06:18:03.725576 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000016 (ops 75-79)
I20260812 06:18:03.725612 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000017 (ops 80-84)
I20260812 06:18:03.725704 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000018 (ops 85-88)
I20260812 06:18:03.725749 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000019 (ops 89-93)
I20260812 06:18:03.725797 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000020 (ops 94-98)
I20260812 06:18:03.725837 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000021 (ops 99-103)
I20260812 06:18:03.725878 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000022 (ops 104-108)
I20260812 06:18:03.725921 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000023 (ops 109-112)
I20260812 06:18:03.726022 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000024 (ops 113-117)
I20260812 06:18:03.726064 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000025 (ops 118-122)
I20260812 06:18:03.726109 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000026 (ops 123-127)
I20260812 06:18:03.757354 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: LogGCOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.032s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:18:03.757906 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=5.165500
I20260812 06:18:03.781054 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.023s	user 0.018s	sys 0.004s Metrics: {"bytes_written":6851279,"delete_count":0,"lbm_write_time_us":10129,"lbm_writes_lt_1ms":170,"reinsert_count":0,"update_count":835}
I20260812 06:18:03.781606 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:03.788340 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.007s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1353977,"delete_count":0,"lbm_write_time_us":1963,"lbm_writes_lt_1ms":36,"reinsert_count":0,"update_count":165}
I20260812 06:18:03.788838 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:04.034540 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.246s	user 0.168s	sys 0.075s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082214,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1919,"lbm_read_time_us":20432,"lbm_reads_lt_1ms":875,"lbm_write_time_us":41796,"lbm_writes_lt_1ms":843,"mutex_wait_us":430,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":17152,"thread_start_us":104,"threads_started":1,"update_count":4000}
I20260812 06:18:04.035333 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=19.056125
I20260812 06:18:04.114709 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.079s	user 0.034s	sys 0.036s Metrics: {"bytes_written":20922555,"delete_count":0,"lbm_write_time_us":35253,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":510,"reinsert_count":0,"update_count":2550}
I20260812 06:18:04.115211 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling UndoDeltaBlockGCOp(89e4808e4c1e43efa239214830d18791): 491 bytes on disk
I20260812 06:18:04.115639 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: UndoDeltaBlockGCOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:18:04.116135 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=6.157687
I20260812 06:18:04.141583 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.025s	user 0.023s	sys 0.000s Metrics: {"bytes_written":7794838,"delete_count":0,"lbm_write_time_us":10168,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:04.142236 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:04.349332 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.207s	user 0.146s	sys 0.054s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979515,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1275,"lbm_read_time_us":15417,"lbm_reads_lt_1ms":764,"lbm_write_time_us":42507,"lbm_writes_lt_1ms":743,"mutex_wait_us":268,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3500}
I20260812 06:18:04.350085 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=18.063937
I20260812 06:18:04.404830 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.055s	user 0.042s	sys 0.012s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":24101,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:04.405509 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:04.425756 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.020s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6812,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":500}
I20260812 06:18:04.426357 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:04.608649 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.182s	user 0.131s	sys 0.047s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":623,"lbm_read_time_us":11114,"lbm_reads_lt_1ms":664,"lbm_write_time_us":35111,"lbm_writes_lt_1ms":643,"mutex_wait_us":3405,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":3000}
I20260812 06:18:04.611873 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=14.095187
I20260812 06:18:04.661563 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.049s	user 0.037s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21653,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:04.662240 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:04.678584 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.016s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6303,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.679164 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:04.843879 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.164s	user 0.112s	sys 0.045s 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":743,"lbm_read_time_us":11635,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28113,"lbm_writes_lt_1ms":543,"mutex_wait_us":356,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:18:04.844631 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=14.095187
I20260812 06:18:04.900192 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.055s	user 0.023s	sys 0.029s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24919,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:04.900779 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:05.054971 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.154s	user 0.085s	sys 0.063s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":235,"lbm_read_time_us":9929,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25550,"lbm_writes_lt_1ms":443,"mutex_wait_us":85,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:05.055673 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=14.095187
I20260812 06:18:05.101743 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.046s	user 0.025s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19300,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.102216 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:05.113821 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4363,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.114377 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushMRSOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:05.152220 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushMRSOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.038s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":34,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":1474,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1647,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:05.152909 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling LogGCOp(89e4808e4c1e43efa239214830d18791): free 121006752 bytes of WAL
I20260812 06:18:05.153146 29628 log_reader.cc:385] T 89e4808e4c1e43efa239214830d18791: removed 12 log segments from log reader
I20260812 06:18:05.153213 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000027 (ops 128-132)
I20260812 06:18:05.153268 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000028 (ops 133-136)
I20260812 06:18:05.153324 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000029 (ops 137-141)
I20260812 06:18:05.153367 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000030 (ops 142-146)
I20260812 06:18:05.153402 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000031 (ops 147-151)
I20260812 06:18:05.153450 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000032 (ops 152-156)
I20260812 06:18:05.153486 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000033 (ops 157-161)
I20260812 06:18:05.153522 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000034 (ops 162-166)
I20260812 06:18:05.153558 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000035 (ops 167-171)
I20260812 06:18:05.153594 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000036 (ops 172-176)
I20260812 06:18:05.153630 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000037 (ops 177-181)
I20260812 06:18:05.153667 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000038 (ops 182-186)
I20260812 06:18:05.180051 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: LogGCOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.027s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:18:05.180431 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling UndoDeltaBlockGCOp(89e4808e4c1e43efa239214830d18791): 462 bytes on disk
I20260812 06:18:05.180892 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: UndoDeltaBlockGCOp(89e4808e4c1e43efa239214830d18791) 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:18:05.181419 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=3.181125
I20260812 06:18:05.207257 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.026s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4630,"lbm_writes_lt_1ms":113,"mutex_wait_us":219,"reinsert_count":0,"update_count":550}
I20260812 06:18:05.207765 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling LogGCOp(89e4808e4c1e43efa239214830d18791): free 11564891 bytes of WAL
I20260812 06:18:05.208022 29628 log_reader.cc:385] T 89e4808e4c1e43efa239214830d18791: removed 1 log segments from log reader
I20260812 06:18:05.208087 29628 log.cc:1079] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: Deleting log segment in path: /tmp/dist-test-taskDAwrid/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474847716-29305-0/minicluster-data/ts-0-root/wals/89e4808e4c1e43efa239214830d18791/wal-000000039 (ops 187-190)
I20260812 06:18:05.211005 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: LogGCOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:05.211344 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=2.188937
I20260812 06:18:05.225781 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5130,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:05.226502 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791): perf score=1.000000
I20260812 06:18:05.477988 29305 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.953s	user 1.780s	sys 0.192s
I20260812 06:18:05.492193 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: MajorDeltaCompactionOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.265s	user 0.155s	sys 0.095s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979740,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":5212,"lbm_read_time_us":16407,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42610,"lbm_writes_lt_1ms":743,"mutex_wait_us":2146,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":114,"threads_started":1,"update_count":3500}
I20260812 06:18:05.493042 29695 maintenance_manager.cc:419] P 21ea01bc35c34b39928c1c174080a682: Scheduling FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791): perf score=18.063937
I20260812 06:18:05.539480 29305 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.061s	user 0.001s	sys 0.000s
I20260812 06:18:05.540053 29305 tablet_server.cc:179] TabletServer@127.28.158.65:0 shutting down...
I20260812 06:18:05.559850 29628 maintenance_manager.cc:643] P 21ea01bc35c34b39928c1c174080a682: FlushDeltaMemStoresOp(89e4808e4c1e43efa239214830d18791) complete. Timing: real 0.067s	user 0.043s	sys 0.020s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":30455,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:05.560441 29305 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:05.560693 29305 tablet_replica.cc:333] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682: stopping tablet replica
I20260812 06:18:05.560837 29305 raft_consensus.cc:2243] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:05.561033 29305 raft_consensus.cc:2272] T 89e4808e4c1e43efa239214830d18791 P 21ea01bc35c34b39928c1c174080a682 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:05.564210 29305 tablet_server.cc:196] TabletServer@127.28.158.65:0 shutdown complete.
I20260812 06:18:05.566951 29305 master.cc:562] Master@127.28.158.126:34485 shutting down...
I20260812 06:18:05.570565 29305 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:05.570753 29305 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:05.570849 29305 tablet_replica.cc:333] T 00000000000000000000000000000000 P f95c114dd5af4b01b5e3141eb4602557: stopping tablet replica
I20260812 06:18:05.583478 29305 master.cc:584] Master@127.28.158.126:34485 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5355 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10814 ms total)

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