[==========] 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:18:23.743686 24006 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.23.113.190:46271
I20260812 06:18:23.744758 24006 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:18:23.745344 24006 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:23.752076 24018 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:18:23.752151 24006 server_base.cc:1061] running on GCE node
W20260812 06:18:23.752080 24014 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:18:23.752439 24013 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:23.753006 24006 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:23.753134 24006 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:23.753206 24006 hybrid_clock.cc:648] HybridClock initialized: now 1786515503753203 us; error 0 us; skew 500 ppm
I20260812 06:18:23.755028 24006 webserver.cc:533] Webserver started at http://127.23.113.190:36239/ using document root <none> and password file <none>
I20260812 06:18:23.755664 24006 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:23.755757 24006 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:23.756017 24006 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:23.757709 24006 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/master-0-root/instance:
uuid: "d793d568895a48f8af74f6a325899645"
format_stamp: "Formatted at 2026-08-12 06:18:23 on dist-test-slave-6k22"
I20260812 06:18:23.761296 24006 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:18:23.763250 24027 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:23.764284 24006 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:23.764421 24006 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/master-0-root
uuid: "d793d568895a48f8af74f6a325899645"
format_stamp: "Formatted at 2026-08-12 06:18:23 on dist-test-slave-6k22"
I20260812 06:18:23.764531 24006 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-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:23.777606 24006 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:23.778210 24006 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:18:23.778414 24006 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:23.786047 24006 rpc_server.cc:307] RPC server started. Bound to: 127.23.113.190:46271
I20260812 06:18:23.786079 24091 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.113.190:46271 every 8 connection(s)
I20260812 06:18:23.788257 24093 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:23.793586 24093 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645: Bootstrap starting.
I20260812 06:18:23.796020 24093 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:23.796907 24093 log.cc:826] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:23.798522 24093 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645: No bootstrap required, opened a new log
I20260812 06:18:23.801257 24093 raft_consensus.cc:359] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d793d568895a48f8af74f6a325899645" member_type: VOTER }
I20260812 06:18:23.801440 24093 raft_consensus.cc:385] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:23.801570 24093 raft_consensus.cc:740] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d793d568895a48f8af74f6a325899645, State: Initialized, Role: FOLLOWER
I20260812 06:18:23.802224 24093 consensus_queue.cc:260] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [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: "d793d568895a48f8af74f6a325899645" member_type: VOTER }
I20260812 06:18:23.802404 24093 raft_consensus.cc:399] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:23.802495 24093 raft_consensus.cc:493] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:23.802624 24093 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:23.803401 24093 raft_consensus.cc:515] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d793d568895a48f8af74f6a325899645" member_type: VOTER }
I20260812 06:18:23.803864 24093 leader_election.cc:304] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [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: d793d568895a48f8af74f6a325899645; no voters: 
I20260812 06:18:23.804180 24093 leader_election.cc:290] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:23.804332 24098 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:23.804615 24098 raft_consensus.cc:697] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [term 1 LEADER]: Becoming Leader. State: Replica: d793d568895a48f8af74f6a325899645, State: Running, Role: LEADER
I20260812 06:18:23.805060 24098 consensus_queue.cc:237] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [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: "d793d568895a48f8af74f6a325899645" member_type: VOTER }
I20260812 06:18:23.805260 24093 sys_catalog.cc:565] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:23.806993 24100 sys_catalog.cc:455] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d793d568895a48f8af74f6a325899645" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d793d568895a48f8af74f6a325899645" member_type: VOTER } }
I20260812 06:18:23.807020 24101 sys_catalog.cc:455] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [sys.catalog]: SysCatalogTable state changed. Reason: New leader d793d568895a48f8af74f6a325899645. Latest consensus state: current_term: 1 leader_uuid: "d793d568895a48f8af74f6a325899645" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d793d568895a48f8af74f6a325899645" member_type: VOTER } }
I20260812 06:18:23.807137 24100 sys_catalog.cc:458] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:23.807137 24101 sys_catalog.cc:458] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:23.807669 24115 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:23.807830 24006 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:23.809823 24115 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:23.813938 24115 catalog_manager.cc:1383] Generated new cluster ID: 3b17d99024074caead5942f364f12020
I20260812 06:18:23.814002 24115 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:23.823381 24115 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:23.824199 24115 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:23.832926 24115 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645: Generated new TSK 0
I20260812 06:18:23.833539 24115 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:23.840422 24006 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:23.843156 24123 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:23.843210 24126 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:23.843202 24124 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:23.843843 24006 server_base.cc:1061] running on GCE node
I20260812 06:18:23.844054 24006 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:23.844107 24006 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:23.844146 24006 hybrid_clock.cc:648] HybridClock initialized: now 1786515503844141 us; error 0 us; skew 500 ppm
I20260812 06:18:23.845188 24006 webserver.cc:533] Webserver started at http://127.23.113.129:39089/ using document root <none> and password file <none>
I20260812 06:18:23.845377 24006 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:23.845453 24006 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:23.845538 24006 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:23.845985 24006 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/instance:
uuid: "021e33fa5cf34b598434fbf00d8c5c59"
format_stamp: "Formatted at 2026-08-12 06:18:23 on dist-test-slave-6k22"
I20260812 06:18:23.847747 24006 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.001s
I20260812 06:18:23.848881 24131 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:23.849186 24006 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:23.849283 24006 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root
uuid: "021e33fa5cf34b598434fbf00d8c5c59"
format_stamp: "Formatted at 2026-08-12 06:18:23 on dist-test-slave-6k22"
I20260812 06:18:23.849375 24006 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-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:23.858181 24006 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:23.859447 24006 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:23.860086 24006 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:23.861115 24006 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:23.861176 24006 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:23.861251 24006 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:23.861300 24006 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:23.869115 24006 rpc_server.cc:307] RPC server started. Bound to: 127.23.113.129:41489
I20260812 06:18:23.869163 24210 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.113.129:41489 every 8 connection(s)
I20260812 06:18:23.885583 24212 heartbeater.cc:344] Connected to a master server at 127.23.113.190:46271
I20260812 06:18:23.885866 24212 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:23.886329 24212 heartbeater.cc:507] Master 127.23.113.190:46271 requested a full tablet report, sending...
I20260812 06:18:23.887948 24050 ts_manager.cc:194] Registered new tserver with Master: 021e33fa5cf34b598434fbf00d8c5c59 (127.23.113.129:41489)
I20260812 06:18:23.888119 24006 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.018285946s
I20260812 06:18:23.889518 24050 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:35188
I20260812 06:18:23.898636 24050 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:35190:
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:23.915136 24163 tablet_service.cc:1511] Processing CreateTablet for tablet 6c3b2946efa640eb8610d11dc46824b1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=de425b0846194615bdb874a78fa479f2]), partition=
I20260812 06:18:23.915627 24163 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6c3b2946efa640eb8610d11dc46824b1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:23.917937 24228 tablet_bootstrap.cc:492] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Bootstrap starting.
I20260812 06:18:23.918841 24228 tablet_bootstrap.cc:654] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:23.920100 24228 tablet_bootstrap.cc:492] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: No bootstrap required, opened a new log
I20260812 06:18:23.920181 24228 ts_tablet_manager.cc:1403] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:23.920637 24228 raft_consensus.cc:359] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "021e33fa5cf34b598434fbf00d8c5c59" member_type: VOTER last_known_addr { host: "127.23.113.129" port: 41489 } }
I20260812 06:18:23.920737 24228 raft_consensus.cc:385] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:23.920760 24228 raft_consensus.cc:740] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 021e33fa5cf34b598434fbf00d8c5c59, State: Initialized, Role: FOLLOWER
I20260812 06:18:23.920930 24228 consensus_queue.cc:260] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59 [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: "021e33fa5cf34b598434fbf00d8c5c59" member_type: VOTER last_known_addr { host: "127.23.113.129" port: 41489 } }
I20260812 06:18:23.921010 24228 raft_consensus.cc:399] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:23.921056 24228 raft_consensus.cc:493] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:23.921113 24228 raft_consensus.cc:3060] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:23.921779 24228 raft_consensus.cc:515] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "021e33fa5cf34b598434fbf00d8c5c59" member_type: VOTER last_known_addr { host: "127.23.113.129" port: 41489 } }
I20260812 06:18:23.921929 24228 leader_election.cc:304] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59 [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: 021e33fa5cf34b598434fbf00d8c5c59; no voters: 
I20260812 06:18:23.922168 24228 leader_election.cc:290] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:23.922258 24230 raft_consensus.cc:2804] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:23.922475 24230 raft_consensus.cc:697] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59 [term 1 LEADER]: Becoming Leader. State: Replica: 021e33fa5cf34b598434fbf00d8c5c59, State: Running, Role: LEADER
I20260812 06:18:23.922542 24228 ts_tablet_manager.cc:1434] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:23.922936 24230 consensus_queue.cc:237] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59 [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: "021e33fa5cf34b598434fbf00d8c5c59" member_type: VOTER last_known_addr { host: "127.23.113.129" port: 41489 } }
I20260812 06:18:23.923682 24212 heartbeater.cc:499] Master 127.23.113.190:46271 was elected leader, sending a full tablet report...
I20260812 06:18:23.926115 24050 catalog_manager.cc:5719] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59 reported cstate change: term changed from 0 to 1, leader changed from <none> to 021e33fa5cf34b598434fbf00d8c5c59 (127.23.113.129). New cstate: current_term: 1 leader_uuid: "021e33fa5cf34b598434fbf00d8c5c59" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "021e33fa5cf34b598434fbf00d8c5c59" member_type: VOTER last_known_addr { host: "127.23.113.129" port: 41489 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:23.994354 24006 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.018s	sys 0.008s
I20260812 06:18:24.120464 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushMRSOp(6c3b2946efa640eb8610d11dc46824b1): perf score=15.086190
I20260812 06:18:24.290913 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushMRSOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.170s	user 0.124s	sys 0.032s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":309,"delete_count":0,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":922,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39556,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":896,"thread_start_us":103,"threads_started":1,"update_count":1450}
I20260812 06:18:24.292224 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling LogGCOp(6c3b2946efa640eb8610d11dc46824b1): free 20743880 bytes of WAL
I20260812 06:18:24.292593 24137 log_reader.cc:385] T 6c3b2946efa640eb8610d11dc46824b1: removed 2 log segments from log reader
I20260812 06:18:24.292666 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000001 (ops 1-6)
I20260812 06:18:24.292725 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000002 (ops 7-11)
I20260812 06:18:24.298370 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: LogGCOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:24.298756 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling UndoDeltaBlockGCOp(6c3b2946efa640eb8610d11dc46824b1): 12719218 bytes on disk
I20260812 06:18:24.299445 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: UndoDeltaBlockGCOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:18:24.299927 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:24.327241 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.027s	user 0.006s	sys 0.008s 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:18:24.327721 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:24.338017 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4028,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.338459 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:24.495162 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.157s	user 0.115s	sys 0.040s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364567,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1050,"lbm_read_time_us":10676,"lbm_reads_lt_1ms":559,"lbm_write_time_us":28103,"lbm_writes_lt_1ms":533,"mutex_wait_us":294,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":317,"threads_started":5,"update_count":2450}
I20260812 06:18:24.495746 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=10.126437
I20260812 06:18:24.539126 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.043s	user 0.030s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16227,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:24.539669 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:24.554260 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5537,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.554766 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:24.695655 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.141s	user 0.125s	sys 0.015s 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":532,"lbm_read_time_us":9434,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29526,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":66304,"update_count":2000}
I20260812 06:18:24.696200 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=11.118625
I20260812 06:18:24.739671 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.043s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":21271,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1550}
I20260812 06:18:24.740263 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:24.752128 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4437,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:24.752547 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:24.886924 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.134s	user 0.106s	sys 0.027s 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":329,"lbm_read_time_us":8345,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27807,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:24.887617 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=10.126437
I20260812 06:18:24.933908 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.046s	user 0.032s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16630,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:24.934408 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:24.945147 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4143,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.945593 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:25.094581 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.149s	user 0.113s	sys 0.036s 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":220,"lbm_read_time_us":11496,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24027,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24960,"update_count":2000}
I20260812 06:18:25.095247 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=10.126437
I20260812 06:18:25.135977 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.041s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":16153,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:18:25.136458 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:25.149019 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4419,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.149701 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:25.287451 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.138s	user 0.109s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":335,"lbm_read_time_us":9968,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27341,"lbm_writes_lt_1ms":443,"mutex_wait_us":75,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2000}
I20260812 06:18:25.288097 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=11.118625
I20260812 06:18:25.328248 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.040s	user 0.020s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17298,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:25.328835 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:25.343721 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5340,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:25.344250 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:25.481977 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.137s	user 0.109s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":93,"lbm_read_time_us":9634,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27283,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":2000}
I20260812 06:18:25.482981 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=10.126437
I20260812 06:18:25.528235 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.045s	user 0.029s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20048,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:25.528715 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:25.541502 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4834,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.541939 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushMRSOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:25.573726 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushMRSOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1414,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1619,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:25.574556 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling LogGCOp(6c3b2946efa640eb8610d11dc46824b1): free 112239312 bytes of WAL
I20260812 06:18:25.574851 24137 log_reader.cc:385] T 6c3b2946efa640eb8610d11dc46824b1: removed 11 log segments from log reader
I20260812 06:18:25.574920 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000003 (ops 12-16)
I20260812 06:18:25.574980 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000004 (ops 17-21)
I20260812 06:18:25.575047 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000005 (ops 22-26)
I20260812 06:18:25.575093 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000006 (ops 27-31)
I20260812 06:18:25.575145 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000007 (ops 32-36)
I20260812 06:18:25.575184 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000008 (ops 37-40)
I20260812 06:18:25.575227 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000009 (ops 41-45)
I20260812 06:18:25.575266 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000010 (ops 46-50)
I20260812 06:18:25.575307 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000011 (ops 51-55)
I20260812 06:18:25.575348 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000012 (ops 56-60)
I20260812 06:18:25.575388 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000013 (ops 61-65)
I20260812 06:18:25.605871 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: LogGCOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:25.606447 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling UndoDeltaBlockGCOp(6c3b2946efa640eb8610d11dc46824b1): 447 bytes on disk
I20260812 06:18:25.607147 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: UndoDeltaBlockGCOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:18:25.607874 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=5.165500
I20260812 06:18:25.627415 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.019s	user 0.013s	sys 0.004s Metrics: {"bytes_written":6400017,"delete_count":0,"lbm_write_time_us":8260,"lbm_writes_lt_1ms":159,"reinsert_count":0,"update_count":780}
I20260812 06:18:25.628083 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:25.637070 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.009s	user 0.005s	sys 0.002s Metrics: {"bytes_written":1805252,"delete_count":0,"lbm_write_time_us":2680,"lbm_writes_lt_1ms":47,"reinsert_count":0,"update_count":220}
I20260812 06:18:25.637523 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:25.813223 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.176s	user 0.151s	sys 0.024s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877286,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":413,"lbm_read_time_us":13243,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33942,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4480,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:18:25.813676 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=14.095187
I20260812 06:18:25.857188 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.043s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19329,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:25.857710 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:25.873736 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6184,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.874151 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:26.033104 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.159s	user 0.114s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":141,"lbm_read_time_us":11202,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29570,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:18:26.034747 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=12.110812
I20260812 06:18:26.074841 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.040s	user 0.024s	sys 0.012s Metrics: {"bytes_written":13661282,"delete_count":0,"lbm_write_time_us":17454,"lbm_writes_lt_1ms":336,"reinsert_count":0,"update_count":1665}
I20260812 06:18:26.075507 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.196750
I20260812 06:18:26.101816 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.026s	user 0.011s	sys 0.001s Metrics: {"bytes_written":2953960,"delete_count":0,"lbm_write_time_us":5172,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:18:26.102514 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:26.113404 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":4150,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:18:26.113832 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:26.304144 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.190s	user 0.107s	sys 0.069s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774776,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":358,"lbm_read_time_us":13602,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30646,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:18:26.304782 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=14.095187
I20260812 06:18:26.365921 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.061s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23256,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.366400 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:26.377198 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4097,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.377810 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:26.550200 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.172s	user 0.113s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":209,"lbm_read_time_us":11583,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29780,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:26.550766 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=14.095187
I20260812 06:18:26.610599 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.060s	user 0.018s	sys 0.031s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":19420,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.611296 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:26.622257 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4292,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.622706 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:26.798887 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.176s	user 0.114s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":166,"lbm_read_time_us":12962,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28892,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:26.799603 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=14.095187
I20260812 06:18:26.861088 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.061s	user 0.035s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21178,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.861721 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:26.873602 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4530,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.874099 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:27.041237 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.167s	user 0.119s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":354,"lbm_read_time_us":12526,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27831,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2500}
I20260812 06:18:27.041875 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=11.118625
I20260812 06:18:27.089218 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.047s	user 0.025s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":22068,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:18:27.090008 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:27.112411 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.022s	user 0.009s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4324,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:27.112886 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:27.131847 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.019s	user 0.003s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3815,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.132400 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushMRSOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:27.169826 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushMRSOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.037s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":1654,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1534,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:27.170646 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling LogGCOp(6c3b2946efa640eb8610d11dc46824b1): free 133024391 bytes of WAL
I20260812 06:18:27.170951 24137 log_reader.cc:385] T 6c3b2946efa640eb8610d11dc46824b1: removed 13 log segments from log reader
I20260812 06:18:27.171020 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000014 (ops 66-70)
I20260812 06:18:27.171073 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000015 (ops 71-74)
I20260812 06:18:27.171133 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000016 (ops 75-79)
I20260812 06:18:27.171191 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000017 (ops 80-84)
I20260812 06:18:27.171259 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000018 (ops 85-89)
I20260812 06:18:27.171310 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000019 (ops 90-94)
I20260812 06:18:27.171337 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000020 (ops 95-99)
I20260812 06:18:27.171365 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000021 (ops 100-104)
I20260812 06:18:27.171409 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000022 (ops 105-109)
I20260812 06:18:27.171439 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000023 (ops 110-114)
I20260812 06:18:27.171479 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000024 (ops 115-119)
I20260812 06:18:27.171535 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000025 (ops 120-124)
I20260812 06:18:27.171599 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000026 (ops 125-129)
I20260812 06:18:27.200004 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: LogGCOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.029s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:18:27.200420 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling UndoDeltaBlockGCOp(6c3b2946efa640eb8610d11dc46824b1): 491 bytes on disk
I20260812 06:18:27.200929 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: UndoDeltaBlockGCOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:18:27.202154 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=3.181125
I20260812 06:18:27.224411 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.022s	user 0.018s	sys 0.000s Metrics: {"bytes_written":4348807,"delete_count":0,"lbm_write_time_us":7628,"lbm_writes_lt_1ms":109,"reinsert_count":0,"update_count":530}
I20260812 06:18:27.224887 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:27.235438 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":4129,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:18:27.235994 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:27.475917 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.240s	user 0.157s	sys 0.081s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979859,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1297,"lbm_read_time_us":17967,"lbm_reads_lt_1ms":775,"lbm_write_time_us":40249,"lbm_writes_lt_1ms":743,"mutex_wait_us":414,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18176,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:18:27.476541 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=18.063937
I20260812 06:18:27.545714 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.068s	user 0.043s	sys 0.012s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":25847,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:27.546227 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:27.558270 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4412,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.558907 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:27.751931 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.193s	user 0.132s	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":593,"lbm_read_time_us":13459,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31174,"lbm_writes_lt_1ms":643,"mutex_wait_us":34,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20992,"update_count":3000}
I20260812 06:18:27.752740 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=14.095187
I20260812 06:18:27.803121 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.050s	user 0.016s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21502,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.803623 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:27.814116 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4205,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.814513 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:28.000631 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.186s	user 0.134s	sys 0.040s 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":767,"lbm_read_time_us":12574,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29395,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21632,"update_count":2500}
I20260812 06:18:28.001165 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=14.095187
I20260812 06:18:28.054538 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.053s	user 0.019s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20601,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.055109 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:28.066129 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.011s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4184,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.067046 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:28.234493 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.167s	user 0.119s	sys 0.044s 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":126,"lbm_read_time_us":12021,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31386,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:28.235188 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=11.118625
I20260812 06:18:28.271078 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.036s	user 0.011s	sys 0.021s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15021,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:28.272022 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:28.289382 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.017s	user 0.003s	sys 0.013s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6331,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:28.289978 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:28.443331 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.153s	user 0.105s	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":197,"lbm_read_time_us":10390,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26223,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:18:28.444178 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=10.126437
I20260812 06:18:28.481096 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.037s	user 0.016s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14821,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:28.481763 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:28.505895 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5381,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.506403 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:28.516806 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3900,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.517268 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:28.694692 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.177s	user 0.122s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774807,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":698,"lbm_read_time_us":12137,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33361,"lbm_writes_lt_1ms":543,"mutex_wait_us":301,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:18:28.695407 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=14.095187
I20260812 06:18:28.748461 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.053s	user 0.021s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22340,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.749022 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=2.188937
I20260812 06:18:28.762405 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4491,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.762878 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushMRSOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:28.797333 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushMRSOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.034s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1353,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1655,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:28.798328 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling LogGCOp(6c3b2946efa640eb8610d11dc46824b1): free 133477714 bytes of WAL
I20260812 06:18:28.798632 24137 log_reader.cc:385] T 6c3b2946efa640eb8610d11dc46824b1: removed 13 log segments from log reader
I20260812 06:18:28.798703 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000027 (ops 130-134)
I20260812 06:18:28.798759 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000028 (ops 135-139)
I20260812 06:18:28.798820 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000029 (ops 140-144)
I20260812 06:18:28.798863 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000030 (ops 145-149)
I20260812 06:18:28.798899 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000031 (ops 150-154)
I20260812 06:18:28.798939 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000032 (ops 155-159)
I20260812 06:18:28.798978 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000033 (ops 160-164)
I20260812 06:18:28.799018 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000034 (ops 165-169)
I20260812 06:18:28.799057 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000035 (ops 170-174)
I20260812 06:18:28.799096 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000036 (ops 175-179)
I20260812 06:18:28.799135 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000037 (ops 180-184)
I20260812 06:18:28.799182 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000038 (ops 185-189)
I20260812 06:18:28.799222 24137 log.cc:1079] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/6c3b2946efa640eb8610d11dc46824b1/wal-000000039 (ops 190-194)
I20260812 06:18:28.831213 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: LogGCOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.033s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:28.831893 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling UndoDeltaBlockGCOp(6c3b2946efa640eb8610d11dc46824b1): 492 bytes on disk
I20260812 06:18:28.832397 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: UndoDeltaBlockGCOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:18:28.833014 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1): perf score=6.157687
I20260812 06:18:28.851811 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: FlushDeltaMemStoresOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.019s	user 0.011s	sys 0.008s Metrics: {"bytes_written":7343571,"delete_count":0,"lbm_write_time_us":7192,"lbm_writes_lt_1ms":182,"reinsert_count":0,"update_count":895}
I20260812 06:18:28.853068 24213 maintenance_manager.cc:419] P 021e33fa5cf34b598434fbf00d8c5c59: Scheduling MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1): perf score=1.000000
I20260812 06:18:28.941442 24006 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.947s	user 1.792s	sys 0.132s
I20260812 06:18:29.084082 24006 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.142s	user 0.003s	sys 0.000s
I20260812 06:18:29.084715 24006 tablet_server.cc:179] TabletServer@127.23.113.129:0 shutting down...
I20260812 06:18:29.109195 24137 maintenance_manager.cc:643] P 021e33fa5cf34b598434fbf00d8c5c59: MajorDeltaCompactionOp(6c3b2946efa640eb8610d11dc46824b1) complete. Timing: real 0.256s	user 0.194s	sys 0.060s Metrics: {"cfile_cache_miss":712,"cfile_cache_miss_bytes":32118125,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1095,"lbm_read_time_us":14056,"lbm_reads_lt_1ms":744,"lbm_write_time_us":46245,"lbm_writes_lt_1ms":722,"mutex_wait_us":298,"peak_mem_usage":85026541,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":76,"threads_started":1,"update_count":3395}
I20260812 06:18:29.110064 24006 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:29.110532 24006 tablet_replica.cc:333] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59: stopping tablet replica
I20260812 06:18:29.110791 24006 raft_consensus.cc:2243] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:29.111063 24006 raft_consensus.cc:2272] T 6c3b2946efa640eb8610d11dc46824b1 P 021e33fa5cf34b598434fbf00d8c5c59 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:29.117626 24006 tablet_server.cc:196] TabletServer@127.23.113.129:0 shutdown complete.
I20260812 06:18:29.166446 24006 master.cc:562] Master@127.23.113.190:46271 shutting down...
I20260812 06:18:29.170014 24006 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:29.170172 24006 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:29.170228 24006 tablet_replica.cc:333] T 00000000000000000000000000000000 P d793d568895a48f8af74f6a325899645: stopping tablet replica
I20260812 06:18:29.182672 24006 master.cc:584] Master@127.23.113.190:46271 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5523 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:29.280122 24006 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.23.113.190:38821
I20260812 06:18:29.280598 24006 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:29.282752 24254 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:29.282814 24250 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:29.282763 24252 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:29.282827 24006 server_base.cc:1061] running on GCE node
I20260812 06:18:29.283123 24006 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:29.283165 24006 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:29.283180 24006 hybrid_clock.cc:648] HybridClock initialized: now 1786515509283181 us; error 0 us; skew 500 ppm
I20260812 06:18:29.284255 24006 webserver.cc:533] Webserver started at http://127.23.113.190:44883/ using document root <none> and password file <none>
I20260812 06:18:29.284442 24006 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:29.284510 24006 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:29.284592 24006 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:29.284994 24006 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/master-0-root/instance:
uuid: "c6579294139941ed8ff47946d7ecf440"
format_stamp: "Formatted at 2026-08-12 06:18:29 on dist-test-slave-6k22"
I20260812 06:18:29.286489 24006 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:29.287366 24260 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:29.287632 24006 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:29.287730 24006 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/master-0-root
uuid: "c6579294139941ed8ff47946d7ecf440"
format_stamp: "Formatted at 2026-08-12 06:18:29 on dist-test-slave-6k22"
I20260812 06:18:29.287818 24006 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-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:29.312042 24006 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:29.312463 24006 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:29.316689 24006 rpc_server.cc:307] RPC server started. Bound to: 127.23.113.190:38821
I20260812 06:18:29.317885 24321 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.113.190:38821 every 8 connection(s)
I20260812 06:18:29.318528 24322 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:29.322167 24322 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440: Bootstrap starting.
I20260812 06:18:29.322958 24322 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:29.323913 24322 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440: No bootstrap required, opened a new log
I20260812 06:18:29.324327 24322 raft_consensus.cc:359] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c6579294139941ed8ff47946d7ecf440" member_type: VOTER }
I20260812 06:18:29.324414 24322 raft_consensus.cc:385] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:29.324471 24322 raft_consensus.cc:740] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c6579294139941ed8ff47946d7ecf440, State: Initialized, Role: FOLLOWER
I20260812 06:18:29.324656 24322 consensus_queue.cc:260] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [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: "c6579294139941ed8ff47946d7ecf440" member_type: VOTER }
I20260812 06:18:29.324728 24322 raft_consensus.cc:399] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:29.324787 24322 raft_consensus.cc:493] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:29.324860 24322 raft_consensus.cc:3060] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:29.325560 24322 raft_consensus.cc:515] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c6579294139941ed8ff47946d7ecf440" member_type: VOTER }
I20260812 06:18:29.325675 24322 leader_election.cc:304] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [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: c6579294139941ed8ff47946d7ecf440; no voters: 
I20260812 06:18:29.325875 24322 leader_election.cc:290] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:29.326126 24325 raft_consensus.cc:2804] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:29.326341 24325 raft_consensus.cc:697] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [term 1 LEADER]: Becoming Leader. State: Replica: c6579294139941ed8ff47946d7ecf440, State: Running, Role: LEADER
I20260812 06:18:29.326385 24322 sys_catalog.cc:565] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:29.326505 24325 consensus_queue.cc:237] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [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: "c6579294139941ed8ff47946d7ecf440" member_type: VOTER }
I20260812 06:18:29.327005 24326 sys_catalog.cc:455] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "c6579294139941ed8ff47946d7ecf440" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c6579294139941ed8ff47946d7ecf440" member_type: VOTER } }
I20260812 06:18:29.327030 24327 sys_catalog.cc:455] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [sys.catalog]: SysCatalogTable state changed. Reason: New leader c6579294139941ed8ff47946d7ecf440. Latest consensus state: current_term: 1 leader_uuid: "c6579294139941ed8ff47946d7ecf440" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c6579294139941ed8ff47946d7ecf440" member_type: VOTER } }
I20260812 06:18:29.327108 24326 sys_catalog.cc:458] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:29.327118 24327 sys_catalog.cc:458] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:29.327373 24332 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:29.328198 24332 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:29.328419 24006 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:29.330099 24332 catalog_manager.cc:1383] Generated new cluster ID: 6ce15ce7f7134cd5b9d87e1d4b587c72
I20260812 06:18:29.330159 24332 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:29.346132 24332 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:29.346712 24332 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:29.351197 24332 catalog_manager.cc:6092] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440: Generated new TSK 0
I20260812 06:18:29.351388 24332 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:29.360764 24006 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:29.362936 24006 server_base.cc:1061] running on GCE node
W20260812 06:18:29.362952 24348 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:29.362917 24345 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:29.362898 24346 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:29.363420 24006 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:29.363484 24006 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:29.363511 24006 hybrid_clock.cc:648] HybridClock initialized: now 1786515509363510 us; error 0 us; skew 500 ppm
I20260812 06:18:29.364377 24006 webserver.cc:533] Webserver started at http://127.23.113.129:44011/ using document root <none> and password file <none>
I20260812 06:18:29.364562 24006 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:29.364632 24006 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:29.364710 24006 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:29.365100 24006 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/instance:
uuid: "d4d0bce396df4461afa46e59f43f7ac9"
format_stamp: "Formatted at 2026-08-12 06:18:29 on dist-test-slave-6k22"
I20260812 06:18:29.366657 24006 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:29.367790 24354 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:29.368059 24006 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:29.368135 24006 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root
uuid: "d4d0bce396df4461afa46e59f43f7ac9"
format_stamp: "Formatted at 2026-08-12 06:18:29 on dist-test-slave-6k22"
I20260812 06:18:29.368196 24006 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-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:29.374171 24006 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:29.374460 24006 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:29.374692 24006 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:29.375196 24006 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:29.375242 24006 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:29.375317 24006 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:29.375355 24006 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:29.379613 24006 rpc_server.cc:307] RPC server started. Bound to: 127.23.113.129:37221
I20260812 06:18:29.380795 24441 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.113.129:37221 every 8 connection(s)
I20260812 06:18:29.391218 24444 heartbeater.cc:344] Connected to a master server at 127.23.113.190:38821
I20260812 06:18:29.391373 24444 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:29.391726 24444 heartbeater.cc:507] Master 127.23.113.190:38821 requested a full tablet report, sending...
I20260812 06:18:29.392405 24279 ts_manager.cc:194] Registered new tserver with Master: d4d0bce396df4461afa46e59f43f7ac9 (127.23.113.129:37221)
I20260812 06:18:29.392490 24006 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01217211s
I20260812 06:18:29.393203 24279 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46456
I20260812 06:18:29.399806 24279 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46462:
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:29.408550 24391 tablet_service.cc:1511] Processing CreateTablet for tablet 4015863a0f6e48db869e8ee75b47c93e (DEFAULT_TABLE table=heavy-update-compaction-test [id=60bd7b5f4e294910ad456bf584cd757b]), partition=
I20260812 06:18:29.408869 24391 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4015863a0f6e48db869e8ee75b47c93e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:29.410982 24461 tablet_bootstrap.cc:492] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Bootstrap starting.
I20260812 06:18:29.411909 24461 tablet_bootstrap.cc:654] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:29.412976 24461 tablet_bootstrap.cc:492] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: No bootstrap required, opened a new log
I20260812 06:18:29.413093 24461 ts_tablet_manager.cc:1403] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:29.413527 24461 raft_consensus.cc:359] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d4d0bce396df4461afa46e59f43f7ac9" member_type: VOTER last_known_addr { host: "127.23.113.129" port: 37221 } }
I20260812 06:18:29.413641 24461 raft_consensus.cc:385] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:29.413709 24461 raft_consensus.cc:740] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d4d0bce396df4461afa46e59f43f7ac9, State: Initialized, Role: FOLLOWER
I20260812 06:18:29.413867 24461 consensus_queue.cc:260] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9 [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: "d4d0bce396df4461afa46e59f43f7ac9" member_type: VOTER last_known_addr { host: "127.23.113.129" port: 37221 } }
I20260812 06:18:29.413991 24461 raft_consensus.cc:399] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:29.414039 24461 raft_consensus.cc:493] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:29.414099 24461 raft_consensus.cc:3060] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:29.414906 24461 raft_consensus.cc:515] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d4d0bce396df4461afa46e59f43f7ac9" member_type: VOTER last_known_addr { host: "127.23.113.129" port: 37221 } }
I20260812 06:18:29.415059 24461 leader_election.cc:304] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9 [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: d4d0bce396df4461afa46e59f43f7ac9; no voters: 
I20260812 06:18:29.415273 24461 leader_election.cc:290] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:29.415359 24463 raft_consensus.cc:2804] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:29.415594 24463 raft_consensus.cc:697] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9 [term 1 LEADER]: Becoming Leader. State: Replica: d4d0bce396df4461afa46e59f43f7ac9, State: Running, Role: LEADER
I20260812 06:18:29.415690 24444 heartbeater.cc:499] Master 127.23.113.190:38821 was elected leader, sending a full tablet report...
I20260812 06:18:29.415817 24463 consensus_queue.cc:237] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9 [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: "d4d0bce396df4461afa46e59f43f7ac9" member_type: VOTER last_known_addr { host: "127.23.113.129" port: 37221 } }
I20260812 06:18:29.415684 24461 ts_tablet_manager.cc:1434] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:29.417191 24279 catalog_manager.cc:5719] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9 reported cstate change: term changed from 0 to 1, leader changed from <none> to d4d0bce396df4461afa46e59f43f7ac9 (127.23.113.129). New cstate: current_term: 1 leader_uuid: "d4d0bce396df4461afa46e59f43f7ac9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d4d0bce396df4461afa46e59f43f7ac9" member_type: VOTER last_known_addr { host: "127.23.113.129" port: 37221 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:29.476447 24006 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.018s	sys 0.004s
I20260812 06:18:29.631384 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushMRSOp(4015863a0f6e48db869e8ee75b47c93e): perf score=19.054940
I20260812 06:18:29.802650 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushMRSOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.171s	user 0.126s	sys 0.037s Metrics: {"bytes_written":16409931,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":822,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44450,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":856,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":2000}
I20260812 06:18:29.803326 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling LogGCOp(4015863a0f6e48db869e8ee75b47c93e): free 20743880 bytes of WAL
I20260812 06:18:29.803548 24361 log_reader.cc:385] T 4015863a0f6e48db869e8ee75b47c93e: removed 2 log segments from log reader
I20260812 06:18:29.803653 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000001 (ops 1-6)
I20260812 06:18:29.803684 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000002 (ops 7-11)
I20260812 06:18:29.807832 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: LogGCOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.004s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:18:29.808157 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:29.820915 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4894,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.821374 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:30.014566 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.193s	user 0.153s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774718,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1152,"lbm_read_time_us":13018,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31153,"lbm_writes_lt_1ms":543,"mutex_wait_us":69,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":29440,"thread_start_us":549,"threads_started":5,"update_count":2500}
I20260812 06:18:30.015441 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling UndoDeltaBlockGCOp(4015863a0f6e48db869e8ee75b47c93e): 16411392 bytes on disk
I20260812 06:18:30.015990 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: UndoDeltaBlockGCOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:18:30.016496 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=14.095187
I20260812 06:18:30.075327 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.059s	user 0.038s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23897,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.075853 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:30.088865 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4331,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.089468 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:30.271960 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.182s	user 0.121s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1769,"lbm_read_time_us":14047,"lbm_reads_lt_1ms":568,"lbm_write_time_us":30377,"lbm_writes_lt_1ms":543,"mutex_wait_us":493,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2500}
I20260812 06:18:30.272646 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=14.095187
I20260812 06:18:30.324857 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.052s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23052,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.325413 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:30.338315 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.013s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4561,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.338866 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:30.506340 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.167s	user 0.139s	sys 0.028s 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":226,"lbm_read_time_us":13376,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26744,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":31744,"update_count":2500}
I20260812 06:18:30.507776 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=14.095187
I20260812 06:18:30.556439 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.048s	user 0.031s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17368,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.557103 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:30.567677 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4092,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.568394 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:30.743037 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.174s	user 0.118s	sys 0.056s 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":209,"lbm_read_time_us":12160,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27499,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25472,"update_count":2500}
I20260812 06:18:30.743707 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=14.095187
I20260812 06:18:30.795924 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.052s	user 0.044s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21436,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.796411 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:30.816413 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.020s	user 0.004s	sys 0.015s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3898,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.816862 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:30.997269 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.180s	user 0.120s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":255,"lbm_read_time_us":13629,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28791,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2500}
I20260812 06:18:30.998155 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=11.118625
I20260812 06:18:31.037113 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.039s	user 0.033s	sys 0.005s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16805,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:31.037586 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:31.051530 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4858,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:31.052271 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushMRSOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:31.107867 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushMRSOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.055s	user 0.033s	sys 0.002s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":27,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1343,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2329,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:31.108740 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=6.157687
I20260812 06:18:31.131511 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.023s	user 0.012s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9502,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:31.132230 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling LogGCOp(4015863a0f6e48db869e8ee75b47c93e): free 121006429 bytes of WAL
I20260812 06:18:31.132582 24361 log_reader.cc:385] T 4015863a0f6e48db869e8ee75b47c93e: removed 12 log segments from log reader
I20260812 06:18:31.132647 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000003 (ops 12-16)
I20260812 06:18:31.132697 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000004 (ops 17-21)
I20260812 06:18:31.132788 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000005 (ops 22-26)
I20260812 06:18:31.132849 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000006 (ops 27-31)
I20260812 06:18:31.132882 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000007 (ops 32-36)
I20260812 06:18:31.132961 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000008 (ops 37-41)
I20260812 06:18:31.133013 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000009 (ops 42-46)
I20260812 06:18:31.133045 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000010 (ops 47-51)
I20260812 06:18:31.133104 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000011 (ops 52-56)
I20260812 06:18:31.133147 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000012 (ops 57-60)
I20260812 06:18:31.133220 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000013 (ops 61-65)
I20260812 06:18:31.133271 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000014 (ops 66-70)
I20260812 06:18:31.161060 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: LogGCOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:31.161715 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling UndoDeltaBlockGCOp(4015863a0f6e48db869e8ee75b47c93e): 472 bytes on disk
I20260812 06:18:31.162382 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: UndoDeltaBlockGCOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:18:31.162904 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:31.173272 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":2174483,"delete_count":0,"lbm_write_time_us":3399,"lbm_writes_lt_1ms":56,"mutex_wait_us":164,"reinsert_count":0,"update_count":265}
I20260812 06:18:31.173647 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:31.179394 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {"bytes_written":1928327,"delete_count":0,"lbm_write_time_us":2105,"lbm_writes_lt_1ms":50,"reinsert_count":0,"update_count":235}
I20260812 06:18:31.179751 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:31.425745 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.246s	user 0.159s	sys 0.084s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979767,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":6624,"lbm_read_time_us":15750,"lbm_reads_lt_1ms":775,"lbm_write_time_us":40724,"lbm_writes_lt_1ms":743,"mutex_wait_us":2016,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9344,"thread_start_us":93,"threads_started":1,"update_count":3500}
I20260812 06:18:31.426440 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=18.063937
I20260812 06:18:31.494875 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.068s	user 0.032s	sys 0.023s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":25908,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:31.495388 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:31.510612 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.015s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5618,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.511214 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:31.721441 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.210s	user 0.110s	sys 0.099s 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":1368,"lbm_read_time_us":12158,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36771,"lbm_writes_lt_1ms":643,"mutex_wait_us":318,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:18:31.722084 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=14.095187
I20260812 06:18:31.764845 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.043s	user 0.022s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18886,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.765358 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:31.780821 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5686,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.781447 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:31.946370 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.165s	user 0.121s	sys 0.044s 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":148,"lbm_read_time_us":12074,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28550,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2500}
I20260812 06:18:31.947093 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=14.095187
I20260812 06:18:31.996598 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.049s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20333,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.997154 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:32.014274 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6603,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.014936 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:32.189373 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.174s	user 0.103s	sys 0.070s 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":853,"lbm_read_time_us":11984,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29232,"lbm_writes_lt_1ms":543,"mutex_wait_us":275,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:32.189936 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=14.095187
I20260812 06:18:32.249030 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.059s	user 0.032s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21847,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:32.249541 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:32.259929 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.010s	user 0.004s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4018,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.260390 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:32.443128 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.183s	user 0.135s	sys 0.040s 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":148,"lbm_read_time_us":13052,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28339,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":2500}
I20260812 06:18:32.443681 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=14.095187
I20260812 06:18:32.507184 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.063s	user 0.040s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20704,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:32.507777 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:32.518282 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4156,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.518780 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushMRSOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:32.562206 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushMRSOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.043s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1643,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1446,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:32.562914 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling LogGCOp(4015863a0f6e48db869e8ee75b47c93e): free 115490133 bytes of WAL
I20260812 06:18:32.563169 24361 log_reader.cc:385] T 4015863a0f6e48db869e8ee75b47c93e: removed 11 log segments from log reader
I20260812 06:18:32.563233 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000015 (ops 71-75)
I20260812 06:18:32.563267 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000016 (ops 76-80)
I20260812 06:18:32.563308 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000017 (ops 81-85)
I20260812 06:18:32.563344 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000018 (ops 86-90)
I20260812 06:18:32.563369 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000019 (ops 91-95)
I20260812 06:18:32.563400 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000020 (ops 96-100)
I20260812 06:18:32.563427 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000021 (ops 101-104)
I20260812 06:18:32.563457 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000022 (ops 105-109)
I20260812 06:18:32.563488 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000023 (ops 110-114)
I20260812 06:18:32.563520 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000024 (ops 115-119)
I20260812 06:18:32.563546 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000025 (ops 120-124)
I20260812 06:18:32.592172 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: LogGCOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:32.592631 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling UndoDeltaBlockGCOp(4015863a0f6e48db869e8ee75b47c93e): 448 bytes on disk
I20260812 06:18:32.593211 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: UndoDeltaBlockGCOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":104,"lbm_reads_lt_1ms":4}
I20260812 06:18:32.593844 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:32.621441 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.027s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5838,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.621882 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:32.632671 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4062,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.633095 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:32.869041 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.236s	user 0.147s	sys 0.086s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979751,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1082,"lbm_read_time_us":16586,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36788,"lbm_writes_lt_1ms":743,"mutex_wait_us":371,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4480,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:18:32.869807 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=18.063937
I20260812 06:18:32.942970 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.073s	user 0.040s	sys 0.020s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":28841,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:32.943434 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:32.954347 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3754,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.954893 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:33.166723 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.212s	user 0.122s	sys 0.089s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1344,"lbm_read_time_us":14051,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34823,"lbm_writes_lt_1ms":643,"mutex_wait_us":593,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19840,"update_count":3000}
I20260812 06:18:33.167528 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=14.095187
I20260812 06:18:33.223464 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.056s	user 0.026s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23669,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.224009 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:33.248711 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.025s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5509,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.249171 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:33.259178 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3931,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.259673 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:33.451521 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.192s	user 0.140s	sys 0.048s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":599,"lbm_read_time_us":14578,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31591,"lbm_writes_lt_1ms":643,"mutex_wait_us":29,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":3000}
I20260812 06:18:33.452463 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=16.079562
I20260812 06:18:33.509964 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.057s	user 0.031s	sys 0.022s Metrics: {"bytes_written":18050868,"delete_count":0,"lbm_write_time_us":23445,"lbm_writes_lt_1ms":443,"reinsert_count":0,"update_count":2200}
I20260812 06:18:33.510444 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=5.165500
I20260812 06:18:33.527462 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.017s	user 0.007s	sys 0.007s Metrics: {"bytes_written":6564117,"delete_count":0,"lbm_write_time_us":6884,"lbm_writes_lt_1ms":163,"reinsert_count":0,"update_count":800}
I20260812 06:18:33.528050 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:33.742264 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.214s	user 0.138s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877107,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":135,"lbm_read_time_us":14284,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35205,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":83072,"update_count":3000}
I20260812 06:18:33.743076 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=18.063937
I20260812 06:18:33.812052 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.069s	user 0.031s	sys 0.024s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25514,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:33.812542 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:33.823870 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4029,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.824465 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:34.028044 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.203s	user 0.160s	sys 0.043s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":97,"lbm_read_time_us":13810,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33051,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":3000}
I20260812 06:18:34.032145 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=15.087375
I20260812 06:18:34.086146 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.053s	user 0.026s	sys 0.024s Metrics: {"bytes_written":16820147,"delete_count":0,"lbm_write_time_us":23994,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:34.086655 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:34.104081 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.017s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4640,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.104565 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:34.114121 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3577,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:34.114557 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushMRSOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:34.149888 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushMRSOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.035s	user 0.030s	sys 0.003s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1364,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2235,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:34.150540 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling LogGCOp(4015863a0f6e48db869e8ee75b47c93e): free 129320713 bytes of WAL
I20260812 06:18:34.150774 24361 log_reader.cc:385] T 4015863a0f6e48db869e8ee75b47c93e: removed 13 log segments from log reader
I20260812 06:18:34.150820 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000026 (ops 125-129)
I20260812 06:18:34.150866 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000027 (ops 130-134)
I20260812 06:18:34.150910 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000028 (ops 135-139)
I20260812 06:18:34.150955 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000029 (ops 140-144)
I20260812 06:18:34.150997 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000030 (ops 145-149)
I20260812 06:18:34.151057 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000031 (ops 150-154)
I20260812 06:18:34.151096 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000032 (ops 155-159)
I20260812 06:18:34.151135 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000033 (ops 160-164)
I20260812 06:18:34.151175 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000034 (ops 165-168)
I20260812 06:18:34.151216 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000035 (ops 169-173)
I20260812 06:18:34.151257 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000036 (ops 174-178)
I20260812 06:18:34.151295 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000037 (ops 179-182)
I20260812 06:18:34.151335 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000038 (ops 183-187)
I20260812 06:18:34.181614 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: LogGCOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:34.184301 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:34.209213 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.025s	user 0.012s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6151,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.209697 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling LogGCOp(4015863a0f6e48db869e8ee75b47c93e): free 12018004 bytes of WAL
I20260812 06:18:34.209985 24361 log_reader.cc:385] T 4015863a0f6e48db869e8ee75b47c93e: removed 1 log segments from log reader
I20260812 06:18:34.210047 24361 log.cc:1079] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: Deleting log segment in path: /tmp/dist-test-taskiN8grq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503732828-24006-0/minicluster-data/ts-0-root/wals/4015863a0f6e48db869e8ee75b47c93e/wal-000000039 (ops 188-192)
I20260812 06:18:34.213207 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: LogGCOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:34.213614 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling UndoDeltaBlockGCOp(4015863a0f6e48db869e8ee75b47c93e): 492 bytes on disk
I20260812 06:18:34.214087 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: UndoDeltaBlockGCOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:18:34.215049 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=2.188937
I20260812 06:18:34.230690 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5871,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.231401 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e): perf score=1.000000
I20260812 06:18:34.406185 24006 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.930s	user 1.823s	sys 0.211s
I20260812 06:18:34.465008 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: MajorDeltaCompactionOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.233s	user 0.159s	sys 0.073s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082271,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"lbm_read_time_us":19631,"lbm_reads_lt_1ms":871,"lbm_write_time_us":42737,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":4000}
I20260812 06:18:34.465523 24445 maintenance_manager.cc:419] P d4d0bce396df4461afa46e59f43f7ac9: Scheduling FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e): perf score=14.095187
I20260812 06:18:34.493532 24006 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.087s	user 0.001s	sys 0.000s
I20260812 06:18:34.494153 24006 tablet_server.cc:179] TabletServer@127.23.113.129:0 shutting down...
I20260812 06:18:34.508081 24361 maintenance_manager.cc:643] P d4d0bce396df4461afa46e59f43f7ac9: FlushDeltaMemStoresOp(4015863a0f6e48db869e8ee75b47c93e) complete. Timing: real 0.042s	user 0.019s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18880,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.509601 24006 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:34.509855 24006 tablet_replica.cc:333] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9: stopping tablet replica
I20260812 06:18:34.509990 24006 raft_consensus.cc:2243] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:34.510205 24006 raft_consensus.cc:2272] T 4015863a0f6e48db869e8ee75b47c93e P d4d0bce396df4461afa46e59f43f7ac9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:34.523891 24006 tablet_server.cc:196] TabletServer@127.23.113.129:0 shutdown complete.
I20260812 06:18:34.547534 24006 master.cc:562] Master@127.23.113.190:38821 shutting down...
I20260812 06:18:34.551023 24006 raft_consensus.cc:2243] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:34.551222 24006 raft_consensus.cc:2272] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:34.551303 24006 tablet_replica.cc:333] T 00000000000000000000000000000000 P c6579294139941ed8ff47946d7ecf440: stopping tablet replica
I20260812 06:18:34.563738 24006 master.cc:584] Master@127.23.113.190:38821 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5382 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10907 ms total)

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