[==========] 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:09.100327 30199 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.125.254:38325
I20260812 06:18:09.101404 30199 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:09.102023 30199 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:09.109030 30205 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:09.109228 30208 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:09.109351 30199 server_base.cc:1061] running on GCE node
W20260812 06:18:09.109520 30204 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:09.110059 30199 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:09.110169 30199 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:09.110208 30199 hybrid_clock.cc:648] HybridClock initialized: now 1786515489110206 us; error 0 us; skew 500 ppm
I20260812 06:18:09.112207 30199 webserver.cc:533] Webserver started at http://127.29.125.254:44983/ using document root <none> and password file <none>
I20260812 06:18:09.112824 30199 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:09.112890 30199 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:09.113094 30199 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:09.114770 30199 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/master-0-root/instance:
uuid: "5423ec936ff046a187e63f353ef191fc"
format_stamp: "Formatted at 2026-08-12 06:18:09 on dist-test-slave-10pc"
I20260812 06:18:09.118667 30199 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:18:09.120967 30213 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:09.122021 30199 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:09.122306 30199 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/master-0-root
uuid: "5423ec936ff046a187e63f353ef191fc"
format_stamp: "Formatted at 2026-08-12 06:18:09 on dist-test-slave-10pc"
I20260812 06:18:09.122445 30199 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-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:09.143035 30199 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:09.143750 30199 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:09.143957 30199 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:09.152390 30199 rpc_server.cc:307] RPC server started. Bound to: 127.29.125.254:38325
I20260812 06:18:09.152390 30275 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.125.254:38325 every 8 connection(s)
I20260812 06:18:09.155157 30276 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:09.161370 30276 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc: Bootstrap starting.
I20260812 06:18:09.163766 30276 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:09.164791 30276 log.cc:826] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:09.166568 30276 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc: No bootstrap required, opened a new log
I20260812 06:18:09.169472 30276 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5423ec936ff046a187e63f353ef191fc" member_type: VOTER }
I20260812 06:18:09.169643 30276 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:09.169785 30276 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5423ec936ff046a187e63f353ef191fc, State: Initialized, Role: FOLLOWER
I20260812 06:18:09.170466 30276 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [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: "5423ec936ff046a187e63f353ef191fc" member_type: VOTER }
I20260812 06:18:09.170641 30276 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:09.170717 30276 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:09.170868 30276 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:09.171696 30276 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5423ec936ff046a187e63f353ef191fc" member_type: VOTER }
I20260812 06:18:09.172155 30276 leader_election.cc:304] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [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: 5423ec936ff046a187e63f353ef191fc; no voters: 
I20260812 06:18:09.172516 30276 leader_election.cc:290] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:09.172704 30279 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:09.172959 30279 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [term 1 LEADER]: Becoming Leader. State: Replica: 5423ec936ff046a187e63f353ef191fc, State: Running, Role: LEADER
I20260812 06:18:09.173370 30279 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [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: "5423ec936ff046a187e63f353ef191fc" member_type: VOTER }
I20260812 06:18:09.173581 30276 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:09.175480 30281 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5423ec936ff046a187e63f353ef191fc. Latest consensus state: current_term: 1 leader_uuid: "5423ec936ff046a187e63f353ef191fc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5423ec936ff046a187e63f353ef191fc" member_type: VOTER } }
I20260812 06:18:09.175460 30280 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5423ec936ff046a187e63f353ef191fc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5423ec936ff046a187e63f353ef191fc" member_type: VOTER } }
I20260812 06:18:09.175611 30280 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:09.175611 30281 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:09.175948 30199 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:09.176095 30294 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:09.178634 30294 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:09.183674 30294 catalog_manager.cc:1383] Generated new cluster ID: 33f81548151c4b6f9fb7fd0469304804
I20260812 06:18:09.183759 30294 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:09.204118 30294 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:09.205387 30294 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:09.217456 30294 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc: Generated new TSK 0
I20260812 06:18:09.218238 30294 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:09.241010 30199 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:09.243875 30199 server_base.cc:1061] running on GCE node
W20260812 06:18:09.243745 30303 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:09.243750 30300 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:09.243929 30301 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:09.244378 30199 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:09.244442 30199 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:09.244488 30199 hybrid_clock.cc:648] HybridClock initialized: now 1786515489244487 us; error 0 us; skew 500 ppm
I20260812 06:18:09.245468 30199 webserver.cc:533] Webserver started at http://127.29.125.193:39283/ using document root <none> and password file <none>
I20260812 06:18:09.245656 30199 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:09.245728 30199 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:09.245812 30199 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:09.246234 30199 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/instance:
uuid: "74ee26f6f0404032b37b26d08304e725"
format_stamp: "Formatted at 2026-08-12 06:18:09 on dist-test-slave-10pc"
I20260812 06:18:09.247773 30199 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:09.248795 30308 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:09.249042 30199 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:09.249120 30199 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root
uuid: "74ee26f6f0404032b37b26d08304e725"
format_stamp: "Formatted at 2026-08-12 06:18:09 on dist-test-slave-10pc"
I20260812 06:18:09.249207 30199 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-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:09.263374 30199 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:09.263898 30199 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:09.264487 30199 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:09.265477 30199 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:09.265535 30199 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:09.265614 30199 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:09.265652 30199 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:09.273156 30199 rpc_server.cc:307] RPC server started. Bound to: 127.29.125.193:35171
I20260812 06:18:09.273180 30376 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.125.193:35171 every 8 connection(s)
I20260812 06:18:09.287808 30377 heartbeater.cc:344] Connected to a master server at 127.29.125.254:38325
I20260812 06:18:09.288071 30377 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:09.288635 30377 heartbeater.cc:507] Master 127.29.125.254:38325 requested a full tablet report, sending...
I20260812 06:18:09.290050 30230 ts_manager.cc:194] Registered new tserver with Master: 74ee26f6f0404032b37b26d08304e725 (127.29.125.193:35171)
I20260812 06:18:09.290625 30199 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016756837s
I20260812 06:18:09.291460 30230 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49212
I20260812 06:18:09.300338 30230 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49228:
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:09.314709 30337 tablet_service.cc:1511] Processing CreateTablet for tablet 821ca6294a664fc2861df927acc43157 (DEFAULT_TABLE table=heavy-update-compaction-test [id=2a055e7357104164b78a11f7281d22d7]), partition=
I20260812 06:18:09.315289 30337 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 821ca6294a664fc2861df927acc43157. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:09.317939 30390 tablet_bootstrap.cc:492] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Bootstrap starting.
I20260812 06:18:09.319227 30390 tablet_bootstrap.cc:654] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:09.321030 30390 tablet_bootstrap.cc:492] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: No bootstrap required, opened a new log
I20260812 06:18:09.321146 30390 ts_tablet_manager.cc:1403] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:09.321722 30390 raft_consensus.cc:359] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74ee26f6f0404032b37b26d08304e725" member_type: VOTER last_known_addr { host: "127.29.125.193" port: 35171 } }
I20260812 06:18:09.321836 30390 raft_consensus.cc:385] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:09.321862 30390 raft_consensus.cc:740] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 74ee26f6f0404032b37b26d08304e725, State: Initialized, Role: FOLLOWER
I20260812 06:18:09.322072 30390 consensus_queue.cc:260] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725 [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: "74ee26f6f0404032b37b26d08304e725" member_type: VOTER last_known_addr { host: "127.29.125.193" port: 35171 } }
I20260812 06:18:09.322184 30390 raft_consensus.cc:399] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:09.322260 30390 raft_consensus.cc:493] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:09.322327 30390 raft_consensus.cc:3060] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:09.323372 30390 raft_consensus.cc:515] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74ee26f6f0404032b37b26d08304e725" member_type: VOTER last_known_addr { host: "127.29.125.193" port: 35171 } }
I20260812 06:18:09.323544 30390 leader_election.cc:304] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725 [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: 74ee26f6f0404032b37b26d08304e725; no voters: 
I20260812 06:18:09.323851 30390 leader_election.cc:290] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:09.323974 30392 raft_consensus.cc:2804] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:09.324184 30392 raft_consensus.cc:697] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725 [term 1 LEADER]: Becoming Leader. State: Replica: 74ee26f6f0404032b37b26d08304e725, State: Running, Role: LEADER
I20260812 06:18:09.324287 30390 ts_tablet_manager.cc:1434] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Time spent starting tablet: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:09.324349 30392 consensus_queue.cc:237] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725 [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: "74ee26f6f0404032b37b26d08304e725" member_type: VOTER last_known_addr { host: "127.29.125.193" port: 35171 } }
I20260812 06:18:09.324769 30377 heartbeater.cc:499] Master 127.29.125.254:38325 was elected leader, sending a full tablet report...
I20260812 06:18:09.327442 30230 catalog_manager.cc:5719] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725 reported cstate change: term changed from 0 to 1, leader changed from <none> to 74ee26f6f0404032b37b26d08304e725 (127.29.125.193). New cstate: current_term: 1 leader_uuid: "74ee26f6f0404032b37b26d08304e725" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74ee26f6f0404032b37b26d08304e725" member_type: VOTER last_known_addr { host: "127.29.125.193" port: 35171 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:09.399158 30199 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.062s	user 0.017s	sys 0.012s
I20260812 06:18:09.524493 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushMRSOp(821ca6294a664fc2861df927acc43157): perf score=15.086190
I20260812 06:18:09.695250 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushMRSOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.170s	user 0.102s	sys 0.051s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":205,"delete_count":0,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1256,"drs_written":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37928,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":116,"threads_started":1,"update_count":1450}
I20260812 06:18:09.696549 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling LogGCOp(821ca6294a664fc2861df927acc43157): free 20743880 bytes of WAL
I20260812 06:18:09.696882 30313 log_reader.cc:385] T 821ca6294a664fc2861df927acc43157: removed 2 log segments from log reader
I20260812 06:18:09.696950 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000001 (ops 1-6)
I20260812 06:18:09.697014 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000002 (ops 7-11)
I20260812 06:18:09.703044 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: LogGCOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:09.703557 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling UndoDeltaBlockGCOp(821ca6294a664fc2861df927acc43157): 12719217 bytes on disk
I20260812 06:18:09.704227 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: UndoDeltaBlockGCOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:18:09.704680 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:09.726449 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.022s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7089,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.726986 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:09.854152 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.127s	user 0.091s	sys 0.035s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1121,"lbm_read_time_us":9162,"lbm_reads_lt_1ms":450,"lbm_write_time_us":22008,"lbm_writes_lt_1ms":433,"mutex_wait_us":139,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":14336,"thread_start_us":347,"threads_started":5,"update_count":1950}
I20260812 06:18:09.854777 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=10.126437
I20260812 06:18:09.892905 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.038s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18305,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:18:09.893380 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:09.910465 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6101,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.911087 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:10.036150 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.125s	user 0.095s	sys 0.029s 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":763,"lbm_read_time_us":8213,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23670,"lbm_writes_lt_1ms":443,"mutex_wait_us":353,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.036837 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=10.126437
I20260812 06:18:10.079509 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.042s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20335,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.080047 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:10.090529 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4067,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.091176 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:10.223013 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.132s	user 0.105s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":333,"lbm_read_time_us":10055,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24949,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:18:10.223563 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=10.126437
I20260812 06:18:10.283921 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.060s	user 0.020s	sys 0.023s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17133,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.284521 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:10.295676 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4384,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.296284 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:10.442850 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.146s	user 0.117s	sys 0.029s 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":980,"lbm_read_time_us":11232,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22266,"lbm_writes_lt_1ms":443,"mutex_wait_us":337,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2000}
I20260812 06:18:10.443356 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=10.126437
I20260812 06:18:10.483338 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.040s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16950,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.483875 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:10.499353 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5733,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.499915 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:10.629063 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.129s	user 0.108s	sys 0.017s 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":725,"lbm_read_time_us":9522,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24457,"lbm_writes_lt_1ms":443,"mutex_wait_us":70,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:18:10.629709 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=10.126437
I20260812 06:18:10.676266 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.046s	user 0.018s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14207,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.676891 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:10.688315 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4178,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.688925 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:10.809185 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.120s	user 0.100s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":789,"lbm_read_time_us":7855,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25159,"lbm_writes_lt_1ms":443,"mutex_wait_us":81,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:18:10.809899 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=10.126437
I20260812 06:18:10.856987 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.047s	user 0.024s	sys 0.020s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15786,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.857565 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:10.868558 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4292,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.869037 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:11.020666 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.151s	user 0.100s	sys 0.049s 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":1042,"lbm_read_time_us":11500,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25065,"lbm_writes_lt_1ms":443,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:11.021474 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=10.126437
I20260812 06:18:11.066272 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.045s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15302,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.066744 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:11.077873 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4243,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.078708 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushMRSOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:11.110234 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushMRSOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.031s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":165,"dirs.run_wall_time_us":1216,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2136,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:11.111181 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling LogGCOp(821ca6294a664fc2861df927acc43157): free 124257246 bytes of WAL
I20260812 06:18:11.111514 30313 log_reader.cc:385] T 821ca6294a664fc2861df927acc43157: removed 12 log segments from log reader
I20260812 06:18:11.111596 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000003 (ops 12-16)
I20260812 06:18:11.111652 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000004 (ops 17-21)
I20260812 06:18:11.111713 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000005 (ops 22-26)
I20260812 06:18:11.111753 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000006 (ops 27-31)
I20260812 06:18:11.111791 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000007 (ops 32-36)
I20260812 06:18:11.111827 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000008 (ops 37-41)
I20260812 06:18:11.111864 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000009 (ops 42-46)
I20260812 06:18:11.111900 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000010 (ops 47-51)
I20260812 06:18:11.111936 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000011 (ops 52-56)
I20260812 06:18:11.111975 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000012 (ops 57-61)
I20260812 06:18:11.112013 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000013 (ops 62-66)
I20260812 06:18:11.112049 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000014 (ops 67-70)
I20260812 06:18:11.141121 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: LogGCOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.030s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:18:11.141786 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling UndoDeltaBlockGCOp(821ca6294a664fc2861df927acc43157): 482 bytes on disk
I20260812 06:18:11.142431 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: UndoDeltaBlockGCOp(821ca6294a664fc2861df927acc43157) 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:11.143160 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=3.181125
I20260812 06:18:11.160176 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.017s	user 0.013s	sys 0.002s Metrics: {"bytes_written":4677002,"delete_count":0,"lbm_write_time_us":6115,"lbm_writes_lt_1ms":117,"reinsert_count":0,"update_count":570}
I20260812 06:18:11.160715 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:11.174821 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.014s	user 0.002s	sys 0.010s Metrics: {"bytes_written":3528305,"delete_count":0,"lbm_write_time_us":5272,"lbm_writes_lt_1ms":89,"reinsert_count":0,"update_count":430}
I20260812 06:18:11.175422 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:11.381156 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.206s	user 0.149s	sys 0.051s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":687,"lbm_read_time_us":15569,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33915,"lbm_writes_lt_1ms":643,"mutex_wait_us":67,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18560,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:18:11.381896 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=14.095187
I20260812 06:18:11.445468 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.063s	user 0.035s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21275,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:11.446017 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:11.456770 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4238,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.457224 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:11.633701 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.176s	user 0.124s	sys 0.052s 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":166,"lbm_read_time_us":12417,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30501,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:18:11.634527 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=11.118625
I20260812 06:18:11.671845 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.037s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16267,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:11.672765 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:11.708823 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.036s	user 0.009s	sys 0.016s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5916,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:11.709427 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:11.720304 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4216,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.720963 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:11.912667 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.191s	user 0.111s	sys 0.070s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":679,"lbm_read_time_us":12462,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30261,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:11.913401 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=14.095187
I20260812 06:18:11.963745 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.050s	user 0.018s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24190,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:11.964339 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:11.988102 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.024s	user 0.011s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5636,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.988895 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:12.180631 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.192s	user 0.122s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1263,"lbm_read_time_us":11131,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34470,"lbm_writes_lt_1ms":543,"mutex_wait_us":379,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:18:12.181200 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=14.095187
I20260812 06:18:12.231753 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.050s	user 0.022s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22585,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:12.232345 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:12.247735 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5559,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.248323 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:12.409884 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.161s	user 0.115s	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":478,"lbm_read_time_us":11028,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31035,"lbm_writes_lt_1ms":543,"mutex_wait_us":263,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:18:12.410612 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=11.118625
I20260812 06:18:12.457580 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.047s	user 0.031s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17565,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:12.458181 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:12.479749 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.021s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.480295 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:12.490036 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.010s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3554,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:12.490568 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:12.634799 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.144s	user 0.113s	sys 0.029s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":301,"lbm_read_time_us":8789,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27781,"lbm_writes_lt_1ms":543,"mutex_wait_us":85,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:12.635507 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=11.118625
I20260812 06:18:12.675086 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.039s	user 0.031s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16723,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:12.675921 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:12.699282 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.023s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4708,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:12.699757 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:12.710065 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3817,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.710592 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushMRSOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:12.747098 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushMRSOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.036s	user 0.033s	sys 0.001s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1315,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2193,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:12.747916 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling LogGCOp(821ca6294a664fc2861df927acc43157): free 133024398 bytes of WAL
I20260812 06:18:12.748265 30313 log_reader.cc:385] T 821ca6294a664fc2861df927acc43157: removed 13 log segments from log reader
I20260812 06:18:12.748330 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000015 (ops 71-75)
I20260812 06:18:12.748371 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000016 (ops 76-80)
I20260812 06:18:12.748402 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000017 (ops 81-85)
I20260812 06:18:12.748433 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000018 (ops 86-90)
I20260812 06:18:12.748482 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000019 (ops 91-95)
I20260812 06:18:12.748518 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000020 (ops 96-100)
I20260812 06:18:12.748554 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000021 (ops 101-105)
I20260812 06:18:12.748577 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000022 (ops 106-110)
I20260812 06:18:12.748600 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000023 (ops 111-115)
I20260812 06:18:12.748637 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000024 (ops 116-120)
I20260812 06:18:12.748667 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000025 (ops 121-124)
I20260812 06:18:12.748703 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000026 (ops 125-129)
I20260812 06:18:12.748735 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000027 (ops 130-134)
I20260812 06:18:12.780151 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: LogGCOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.032s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:18:12.780742 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=3.181125
I20260812 06:18:12.800737 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.020s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7095,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:12.801281 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:12.819648 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.018s	user 0.004s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3694,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:12.820195 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:13.054782 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.234s	user 0.128s	sys 0.107s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979851,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":603,"lbm_read_time_us":17123,"lbm_reads_lt_1ms":775,"lbm_write_time_us":42444,"lbm_writes_lt_1ms":743,"mutex_wait_us":88,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:18:13.058360 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=14.095187
I20260812 06:18:13.116348 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.058s	user 0.025s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19490,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.117033 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling UndoDeltaBlockGCOp(821ca6294a664fc2861df927acc43157): 493 bytes on disk
I20260812 06:18:13.117523 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: UndoDeltaBlockGCOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:18:13.118047 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:13.129611 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.011s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4679,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.130049 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:13.326157 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.196s	user 0.115s	sys 0.072s 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":879,"lbm_read_time_us":12771,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32664,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:13.327021 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=14.095187
I20260812 06:18:13.388422 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.061s	user 0.036s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20798,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.389076 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:13.406637 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.017s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6706,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.407172 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:13.583871 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.176s	user 0.114s	sys 0.061s 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":371,"lbm_read_time_us":14162,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29094,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:18:13.584625 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=11.118625
I20260812 06:18:13.616899 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.032s	user 0.022s	sys 0.009s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":13303,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:13.617640 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:13.631937 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.014s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4505,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:13.632522 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:13.772190 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.140s	user 0.112s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":271,"lbm_read_time_us":7073,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26420,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2000}
I20260812 06:18:13.772927 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=10.126437
I20260812 06:18:13.810247 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.037s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16457,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.810714 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:13.822435 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4120,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.823060 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:13.946682 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.123s	user 0.102s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":357,"lbm_read_time_us":8256,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22311,"lbm_writes_lt_1ms":443,"mutex_wait_us":102,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.947546 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=10.126437
I20260812 06:18:13.992556 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.045s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15420,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.993183 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:14.003712 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3932,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.004245 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:14.128285 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.124s	user 0.112s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":843,"lbm_read_time_us":8878,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23547,"lbm_writes_lt_1ms":443,"mutex_wait_us":113,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.129079 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=10.126437
I20260812 06:18:14.179569 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.050s	user 0.034s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18140,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:14.180119 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:14.192672 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.012s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4721,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.193219 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushMRSOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:14.234885 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushMRSOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.041s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":1276,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1699,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:14.235860 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling LogGCOp(821ca6294a664fc2861df927acc43157): free 112692556 bytes of WAL
I20260812 06:18:14.236127 30313 log_reader.cc:385] T 821ca6294a664fc2861df927acc43157: removed 11 log segments from log reader
I20260812 06:18:14.236178 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000028 (ops 135-139)
I20260812 06:18:14.236208 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000029 (ops 140-144)
I20260812 06:18:14.236275 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000030 (ops 145-149)
I20260812 06:18:14.236308 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000031 (ops 150-154)
I20260812 06:18:14.236353 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000032 (ops 155-159)
I20260812 06:18:14.236405 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000033 (ops 160-164)
I20260812 06:18:14.236487 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000034 (ops 165-169)
I20260812 06:18:14.236534 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000035 (ops 170-174)
I20260812 06:18:14.236573 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000036 (ops 175-179)
I20260812 06:18:14.236611 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000037 (ops 180-184)
I20260812 06:18:14.236650 30313 log.cc:1079] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/821ca6294a664fc2861df927acc43157/wal-000000038 (ops 185-189)
I20260812 06:18:14.262867 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: LogGCOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.027s	user 0.003s	sys 0.021s Metrics: {}
I20260812 06:18:14.263417 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling UndoDeltaBlockGCOp(821ca6294a664fc2861df927acc43157): 447 bytes on disk
I20260812 06:18:14.264142 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: UndoDeltaBlockGCOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":121,"lbm_reads_lt_1ms":4}
I20260812 06:18:14.264926 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:14.282303 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.017s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4539,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.282752 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=2.188937
I20260812 06:18:14.293628 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.011s	user 0.001s	sys 0.009s 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:14.294166 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157): perf score=1.000000
I20260812 06:18:14.454771 30199 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.056s	user 1.840s	sys 0.148s
I20260812 06:18:14.498977 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: MajorDeltaCompactionOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.205s	user 0.159s	sys 0.043s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877340,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":15867,"lbm_reads_lt_1ms":670,"lbm_write_time_us":35776,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3000}
I20260812 06:18:14.499488 30378 maintenance_manager.cc:419] P 74ee26f6f0404032b37b26d08304e725: Scheduling FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157): perf score=10.126437
I20260812 06:18:14.542287 30199 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.087s	user 0.002s	sys 0.000s
I20260812 06:18:14.542992 30199 tablet_server.cc:179] TabletServer@127.29.125.193:0 shutting down...
I20260812 06:18:14.557732 30313 maintenance_manager.cc:643] P 74ee26f6f0404032b37b26d08304e725: FlushDeltaMemStoresOp(821ca6294a664fc2861df927acc43157) complete. Timing: real 0.058s	user 0.015s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12212,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:14.558415 30199 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:14.558817 30199 tablet_replica.cc:333] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725: stopping tablet replica
I20260812 06:18:14.559064 30199 raft_consensus.cc:2243] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:14.559311 30199 raft_consensus.cc:2272] T 821ca6294a664fc2861df927acc43157 P 74ee26f6f0404032b37b26d08304e725 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:14.574826 30199 tablet_server.cc:196] TabletServer@127.29.125.193:0 shutdown complete.
I20260812 06:18:14.580035 30199 master.cc:562] Master@127.29.125.254:38325 shutting down...
I20260812 06:18:14.583781 30199 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:14.583957 30199 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:14.584026 30199 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5423ec936ff046a187e63f353ef191fc: stopping tablet replica
I20260812 06:18:14.596720 30199 master.cc:584] Master@127.29.125.254:38325 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5596 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:14.696878 30199 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.125.254:42567
I20260812 06:18:14.697300 30199 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:14.699672 30419 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:14.699753 30417 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:14.699750 30416 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:14.699854 30199 server_base.cc:1061] running on GCE node
I20260812 06:18:14.700098 30199 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:14.700147 30199 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:14.700162 30199 hybrid_clock.cc:648] HybridClock initialized: now 1786515494700163 us; error 0 us; skew 500 ppm
I20260812 06:18:14.701043 30199 webserver.cc:533] Webserver started at http://127.29.125.254:35407/ using document root <none> and password file <none>
I20260812 06:18:14.701215 30199 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:14.701260 30199 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:14.701314 30199 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:14.701673 30199 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/master-0-root/instance:
uuid: "448a706d1f604745a3ef4572d25cc8e3"
format_stamp: "Formatted at 2026-08-12 06:18:14 on dist-test-slave-10pc"
I20260812 06:18:14.703142 30199 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:14.704135 30425 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:14.704559 30199 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:14.704658 30199 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/master-0-root
uuid: "448a706d1f604745a3ef4572d25cc8e3"
format_stamp: "Formatted at 2026-08-12 06:18:14 on dist-test-slave-10pc"
I20260812 06:18:14.704742 30199 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-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:14.714402 30199 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:14.714988 30199 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:14.719053 30199 rpc_server.cc:307] RPC server started. Bound to: 127.29.125.254:42567
I20260812 06:18:14.720757 30485 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.125.254:42567 every 8 connection(s)
I20260812 06:18:14.729187 30487 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:14.735220 30487 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3: Bootstrap starting.
I20260812 06:18:14.736095 30487 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:14.737316 30487 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3: No bootstrap required, opened a new log
I20260812 06:18:14.737744 30487 raft_consensus.cc:359] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "448a706d1f604745a3ef4572d25cc8e3" member_type: VOTER }
I20260812 06:18:14.737859 30487 raft_consensus.cc:385] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:14.737924 30487 raft_consensus.cc:740] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 448a706d1f604745a3ef4572d25cc8e3, State: Initialized, Role: FOLLOWER
I20260812 06:18:14.738129 30487 consensus_queue.cc:260] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [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: "448a706d1f604745a3ef4572d25cc8e3" member_type: VOTER }
I20260812 06:18:14.738255 30487 raft_consensus.cc:399] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:14.738304 30487 raft_consensus.cc:493] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:14.738361 30487 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:14.739073 30487 raft_consensus.cc:515] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "448a706d1f604745a3ef4572d25cc8e3" member_type: VOTER }
I20260812 06:18:14.739224 30487 leader_election.cc:304] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [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: 448a706d1f604745a3ef4572d25cc8e3; no voters: 
I20260812 06:18:14.739455 30487 leader_election.cc:290] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:14.739607 30492 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:14.739858 30492 raft_consensus.cc:697] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [term 1 LEADER]: Becoming Leader. State: Replica: 448a706d1f604745a3ef4572d25cc8e3, State: Running, Role: LEADER
I20260812 06:18:14.739943 30487 sys_catalog.cc:565] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:14.740026 30492 consensus_queue.cc:237] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [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: "448a706d1f604745a3ef4572d25cc8e3" member_type: VOTER }
I20260812 06:18:14.740497 30493 sys_catalog.cc:455] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "448a706d1f604745a3ef4572d25cc8e3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "448a706d1f604745a3ef4572d25cc8e3" member_type: VOTER } }
I20260812 06:18:14.740509 30494 sys_catalog.cc:455] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 448a706d1f604745a3ef4572d25cc8e3. Latest consensus state: current_term: 1 leader_uuid: "448a706d1f604745a3ef4572d25cc8e3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "448a706d1f604745a3ef4572d25cc8e3" member_type: VOTER } }
I20260812 06:18:14.740604 30493 sys_catalog.cc:458] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:14.740607 30494 sys_catalog.cc:458] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:14.740903 30497 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:14.741668 30497 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:14.742025 30199 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:14.743474 30497 catalog_manager.cc:1383] Generated new cluster ID: aad3cd84015645d98988dc64c622ba21
I20260812 06:18:14.743532 30497 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:14.760784 30497 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:14.761418 30497 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:14.768368 30497 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3: Generated new TSK 0
I20260812 06:18:14.768630 30497 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:14.774354 30199 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:14.776328 30511 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:14.776415 30514 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:14.776518 30199 server_base.cc:1061] running on GCE node
W20260812 06:18:14.776343 30510 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:14.776803 30199 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:14.776851 30199 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:14.776867 30199 hybrid_clock.cc:648] HybridClock initialized: now 1786515494776867 us; error 0 us; skew 500 ppm
I20260812 06:18:14.777786 30199 webserver.cc:533] Webserver started at http://127.29.125.193:33873/ using document root <none> and password file <none>
I20260812 06:18:14.777966 30199 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:14.778034 30199 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:14.778131 30199 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:14.778525 30199 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/instance:
uuid: "0bfbdc902f5e4cfd84f6268b9dc2e971"
format_stamp: "Formatted at 2026-08-12 06:18:14 on dist-test-slave-10pc"
I20260812 06:18:14.779974 30199 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:14.780920 30520 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:14.781178 30199 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:18:14.781253 30199 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root
uuid: "0bfbdc902f5e4cfd84f6268b9dc2e971"
format_stamp: "Formatted at 2026-08-12 06:18:14 on dist-test-slave-10pc"
I20260812 06:18:14.781307 30199 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-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:14.806842 30199 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:14.807228 30199 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:14.807528 30199 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:14.808079 30199 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:14.808121 30199 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:14.808157 30199 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:14.808172 30199 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:14.812538 30199 rpc_server.cc:307] RPC server started. Bound to: 127.29.125.193:43623
I20260812 06:18:14.812604 30595 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.125.193:43623 every 8 connection(s)
I20260812 06:18:14.817613 30596 heartbeater.cc:344] Connected to a master server at 127.29.125.254:42567
I20260812 06:18:14.817750 30596 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:14.817979 30596 heartbeater.cc:507] Master 127.29.125.254:42567 requested a full tablet report, sending...
I20260812 06:18:14.818676 30446 ts_manager.cc:194] Registered new tserver with Master: 0bfbdc902f5e4cfd84f6268b9dc2e971 (127.29.125.193:43623)
I20260812 06:18:14.819492 30446 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51640
I20260812 06:18:14.819727 30199 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006741584s
I20260812 06:18:14.826915 30446 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51646:
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:14.836514 30552 tablet_service.cc:1511] Processing CreateTablet for tablet cc72a37db98e41c5994d781924c1e00e (DEFAULT_TABLE table=heavy-update-compaction-test [id=f146ee0704764d92b67df44d43a992c3]), partition=
I20260812 06:18:14.836810 30552 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cc72a37db98e41c5994d781924c1e00e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:14.839123 30608 tablet_bootstrap.cc:492] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Bootstrap starting.
I20260812 06:18:14.839928 30608 tablet_bootstrap.cc:654] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:14.841286 30608 tablet_bootstrap.cc:492] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: No bootstrap required, opened a new log
I20260812 06:18:14.841424 30608 ts_tablet_manager.cc:1403] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:14.841908 30608 raft_consensus.cc:359] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0bfbdc902f5e4cfd84f6268b9dc2e971" member_type: VOTER last_known_addr { host: "127.29.125.193" port: 43623 } }
I20260812 06:18:14.842012 30608 raft_consensus.cc:385] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:14.842034 30608 raft_consensus.cc:740] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0bfbdc902f5e4cfd84f6268b9dc2e971, State: Initialized, Role: FOLLOWER
I20260812 06:18:14.842154 30608 consensus_queue.cc:260] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971 [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: "0bfbdc902f5e4cfd84f6268b9dc2e971" member_type: VOTER last_known_addr { host: "127.29.125.193" port: 43623 } }
I20260812 06:18:14.842217 30608 raft_consensus.cc:399] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:14.842240 30608 raft_consensus.cc:493] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:14.842278 30608 raft_consensus.cc:3060] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:14.842964 30608 raft_consensus.cc:515] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0bfbdc902f5e4cfd84f6268b9dc2e971" member_type: VOTER last_known_addr { host: "127.29.125.193" port: 43623 } }
I20260812 06:18:14.843089 30608 leader_election.cc:304] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971 [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: 0bfbdc902f5e4cfd84f6268b9dc2e971; no voters: 
I20260812 06:18:14.843247 30608 leader_election.cc:290] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:14.843389 30611 raft_consensus.cc:2804] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:14.843533 30608 ts_tablet_manager.cc:1434] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:14.843570 30596 heartbeater.cc:499] Master 127.29.125.254:42567 was elected leader, sending a full tablet report...
I20260812 06:18:14.843652 30611 raft_consensus.cc:697] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971 [term 1 LEADER]: Becoming Leader. State: Replica: 0bfbdc902f5e4cfd84f6268b9dc2e971, State: Running, Role: LEADER
I20260812 06:18:14.843806 30611 consensus_queue.cc:237] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971 [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: "0bfbdc902f5e4cfd84f6268b9dc2e971" member_type: VOTER last_known_addr { host: "127.29.125.193" port: 43623 } }
I20260812 06:18:14.845229 30446 catalog_manager.cc:5719] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971 reported cstate change: term changed from 0 to 1, leader changed from <none> to 0bfbdc902f5e4cfd84f6268b9dc2e971 (127.29.125.193). New cstate: current_term: 1 leader_uuid: "0bfbdc902f5e4cfd84f6268b9dc2e971" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0bfbdc902f5e4cfd84f6268b9dc2e971" member_type: VOTER last_known_addr { host: "127.29.125.193" port: 43623 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:14.905582 30199 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.020s	sys 0.003s
I20260812 06:18:15.063421 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushMRSOp(cc72a37db98e41c5994d781924c1e00e): perf score=19.054940
I20260812 06:18:15.218287 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushMRSOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.155s	user 0.113s	sys 0.039s Metrics: {"bytes_written":12307495,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":967,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41161,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:15.218873 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling LogGCOp(cc72a37db98e41c5994d781924c1e00e): free 20743880 bytes of WAL
I20260812 06:18:15.219108 30526 log_reader.cc:385] T cc72a37db98e41c5994d781924c1e00e: removed 2 log segments from log reader
I20260812 06:18:15.219156 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000001 (ops 1-6)
I20260812 06:18:15.219187 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000002 (ops 7-11)
I20260812 06:18:15.223706 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: LogGCOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:15.224310 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:15.240433 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5709,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.241048 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:15.394109 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.153s	user 0.103s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672282,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":582,"lbm_read_time_us":9280,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24591,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16384,"thread_start_us":333,"threads_started":5,"update_count":2000}
I20260812 06:18:15.394829 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=12.110812
I20260812 06:18:15.438123 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.043s	user 0.013s	sys 0.028s Metrics: {"bytes_written":13866409,"delete_count":0,"lbm_write_time_us":19817,"lbm_writes_lt_1ms":341,"reinsert_count":0,"update_count":1690}
I20260812 06:18:15.438582 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.196750
I20260812 06:18:15.463665 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.025s	user 0.004s	sys 0.008s Metrics: {"bytes_written":2953959,"delete_count":0,"lbm_write_time_us":4727,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:18:15.464169 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:15.473766 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3611,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:15.474234 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling UndoDeltaBlockGCOp(cc72a37db98e41c5994d781924c1e00e): 16411392 bytes on disk
I20260812 06:18:15.474658 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: UndoDeltaBlockGCOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:18:15.475039 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:15.646646 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.171s	user 0.125s	sys 0.043s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774773,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":519,"lbm_read_time_us":12281,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27625,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:18:15.649960 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=14.095187
I20260812 06:18:15.703436 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.053s	user 0.028s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21255,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.703965 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:15.714779 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4196,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.715238 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:15.892766 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.177s	user 0.121s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":855,"lbm_read_time_us":13492,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28797,"lbm_writes_lt_1ms":543,"mutex_wait_us":346,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2500}
I20260812 06:18:15.893316 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=14.095187
I20260812 06:18:15.952903 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.059s	user 0.026s	sys 0.029s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18819,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.953612 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:15.970671 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6496,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.971280 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:16.153075 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.182s	user 0.118s	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":309,"lbm_read_time_us":12225,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29142,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:18:16.153604 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=11.118625
I20260812 06:18:16.198839 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.045s	user 0.009s	sys 0.032s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20841,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:18:16.199296 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:16.225155 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.026s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6534,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.225831 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:16.242139 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.016s	user 0.013s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6005,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:16.242785 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:16.432597 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.190s	user 0.112s	sys 0.072s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":875,"lbm_read_time_us":11984,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29840,"lbm_writes_lt_1ms":543,"mutex_wait_us":242,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:18:16.433336 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=14.095187
I20260812 06:18:16.476341 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.043s	user 0.030s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18613,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.476894 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:16.502159 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.025s	user 0.010s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6028,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.502918 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushMRSOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:16.536602 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushMRSOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.033s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1555,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1661,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:16.537237 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling LogGCOp(cc72a37db98e41c5994d781924c1e00e): free 115943180 bytes of WAL
I20260812 06:18:16.537457 30526 log_reader.cc:385] T cc72a37db98e41c5994d781924c1e00e: removed 11 log segments from log reader
I20260812 06:18:16.537511 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000003 (ops 12-16)
I20260812 06:18:16.537540 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000004 (ops 17-21)
I20260812 06:18:16.537581 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000005 (ops 22-26)
I20260812 06:18:16.537624 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000006 (ops 27-31)
I20260812 06:18:16.537654 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000007 (ops 32-36)
I20260812 06:18:16.537706 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000008 (ops 37-41)
I20260812 06:18:16.537744 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000009 (ops 42-46)
I20260812 06:18:16.537782 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000010 (ops 47-51)
I20260812 06:18:16.537819 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000011 (ops 52-56)
I20260812 06:18:16.537859 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000012 (ops 57-61)
I20260812 06:18:16.537899 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000013 (ops 62-66)
I20260812 06:18:16.562218 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: LogGCOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:16.562724 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:16.585075 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.022s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5253,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.585644 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling UndoDeltaBlockGCOp(cc72a37db98e41c5994d781924c1e00e): 462 bytes on disk
I20260812 06:18:16.586397 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: UndoDeltaBlockGCOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":101,"lbm_reads_lt_1ms":4}
I20260812 06:18:16.586894 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:16.597564 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4196,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.598078 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:16.842598 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.244s	user 0.122s	sys 0.112s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":765,"lbm_read_time_us":15326,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39087,"lbm_writes_lt_1ms":743,"mutex_wait_us":86,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17920,"thread_start_us":91,"threads_started":1,"update_count":3500}
I20260812 06:18:16.843328 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=18.063937
I20260812 06:18:16.903962 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.060s	user 0.048s	sys 0.007s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":26521,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:16.904577 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:17.078048 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.173s	user 0.117s	sys 0.056s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774574,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":253,"lbm_read_time_us":13838,"lbm_reads_lt_1ms":563,"lbm_write_time_us":29097,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:17.078763 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=14.095187
I20260812 06:18:17.144678 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.066s	user 0.023s	sys 0.040s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24831,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.145342 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=4.173312
I20260812 06:18:17.163910 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":6071825,"delete_count":0,"lbm_write_time_us":8079,"lbm_writes_lt_1ms":151,"reinsert_count":0,"update_count":740}
I20260812 06:18:17.164498 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:17.171057 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.006s	user 0.001s	sys 0.004s Metrics: {"bytes_written":2133453,"delete_count":0,"lbm_write_time_us":2217,"lbm_writes_lt_1ms":55,"reinsert_count":0,"update_count":260}
I20260812 06:18:17.171934 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:17.360267 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.188s	user 0.124s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877174,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":809,"lbm_read_time_us":14419,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30531,"lbm_writes_lt_1ms":643,"mutex_wait_us":326,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":3000}
I20260812 06:18:17.360904 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=14.095187
I20260812 06:18:17.420794 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.060s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22867,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.421362 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:17.432296 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4385,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.433038 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:17.607553 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.174s	user 0.114s	sys 0.060s 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":754,"lbm_read_time_us":12976,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28975,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:18:17.608336 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=14.095187
I20260812 06:18:17.670364 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.062s	user 0.031s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22912,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.670980 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:17.682163 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4398,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.682709 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:17.854086 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.171s	user 0.127s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":615,"lbm_read_time_us":11590,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27884,"lbm_writes_lt_1ms":543,"mutex_wait_us":292,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":30720,"update_count":2500}
I20260812 06:18:17.854871 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=10.126437
I20260812 06:18:17.887213 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.032s	user 0.029s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13924,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:17.887957 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:17.900888 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4571,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.901468 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:18.080710 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.179s	user 0.108s	sys 0.059s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":240,"lbm_read_time_us":10713,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26355,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.081423 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=11.118625
I20260812 06:18:18.117424 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.036s	user 0.027s	sys 0.008s Metrics: {"bytes_written":13168992,"delete_count":0,"lbm_write_time_us":15809,"lbm_writes_lt_1ms":324,"reinsert_count":0,"update_count":1605}
I20260812 06:18:18.118032 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:18.142575 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.024s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3241130,"delete_count":0,"lbm_write_time_us":4864,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:18:18.143167 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:18.153838 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3896,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.154356 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushMRSOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:18.190955 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushMRSOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.036s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":265,"dirs.run_wall_time_us":1565,"drs_written":1,"lbm_read_time_us":127,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1830,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:18.191694 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling LogGCOp(cc72a37db98e41c5994d781924c1e00e): free 133024380 bytes of WAL
I20260812 06:18:18.191943 30526 log_reader.cc:385] T cc72a37db98e41c5994d781924c1e00e: removed 13 log segments from log reader
I20260812 06:18:18.191991 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000014 (ops 67-71)
I20260812 06:18:18.192020 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000015 (ops 72-76)
I20260812 06:18:18.192101 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000016 (ops 77-81)
I20260812 06:18:18.192162 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000017 (ops 82-86)
I20260812 06:18:18.192205 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000018 (ops 87-91)
I20260812 06:18:18.192263 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000019 (ops 92-96)
I20260812 06:18:18.192309 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000020 (ops 97-100)
I20260812 06:18:18.192353 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000021 (ops 101-105)
I20260812 06:18:18.192391 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000022 (ops 106-110)
I20260812 06:18:18.192431 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000023 (ops 111-115)
I20260812 06:18:18.192492 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000024 (ops 116-120)
I20260812 06:18:18.192533 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000025 (ops 121-125)
I20260812 06:18:18.192571 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000026 (ops 126-130)
I20260812 06:18:18.224208 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: LogGCOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.032s	user 0.002s	sys 0.026s Metrics: {}
I20260812 06:18:18.224685 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling UndoDeltaBlockGCOp(cc72a37db98e41c5994d781924c1e00e): 493 bytes on disk
I20260812 06:18:18.225301 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: UndoDeltaBlockGCOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:18:18.225988 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=4.173312
I20260812 06:18:18.252344 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.026s	user 0.007s	sys 0.015s Metrics: {"bytes_written":5415440,"delete_count":0,"lbm_write_time_us":6668,"lbm_writes_lt_1ms":135,"reinsert_count":0,"update_count":660}
I20260812 06:18:18.253064 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.196750
I20260812 06:18:18.265349 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":4623,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:18:18.265796 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:18.501093 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.235s	user 0.148s	sys 0.087s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979814,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":413,"lbm_read_time_us":16347,"lbm_reads_lt_1ms":775,"lbm_write_time_us":40311,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11904,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:18:18.501809 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=14.095187
I20260812 06:18:18.554194 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.052s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23504,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.554764 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:18.570644 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5969,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.571318 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:18.750892 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.179s	user 0.115s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":445,"lbm_read_time_us":12229,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29452,"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:18.751593 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=14.095187
I20260812 06:18:18.813186 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.061s	user 0.038s	sys 0.014s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18888,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.813742 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:18.824842 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4411,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.825368 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:19.010051 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.184s	user 0.113s	sys 0.060s 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":221,"lbm_read_time_us":12769,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28337,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19712,"update_count":2500}
I20260812 06:18:19.010656 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=14.095187
I20260812 06:18:19.071928 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.061s	user 0.031s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18958,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.072598 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:19.083380 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4252,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.083833 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:19.268716 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.185s	user 0.124s	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":536,"lbm_read_time_us":12415,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30523,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:19.269441 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=11.118625
I20260812 06:18:19.313532 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.044s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16863,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:19.314129 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:19.333245 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.019s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3988,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:19.333724 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:19.344767 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4129,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.345268 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:19.540720 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.195s	user 0.118s	sys 0.073s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":113,"lbm_read_time_us":11521,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30444,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:19.541427 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=14.095187
I20260812 06:18:19.590197 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.049s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20979,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.590772 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:19.602478 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4298,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.603008 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:19.769556 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.166s	user 0.147s	sys 0.016s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":595,"lbm_read_time_us":10395,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31328,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:18:19.770100 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=11.118625
I20260812 06:18:19.806075 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.036s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15531,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:19.806892 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:19.825862 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.019s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5822,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:19.826414 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushMRSOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:19.880123 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushMRSOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.054s	user 0.028s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":1493,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1746,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:19.880981 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling LogGCOp(cc72a37db98e41c5994d781924c1e00e): free 133024661 bytes of WAL
I20260812 06:18:19.881273 30526 log_reader.cc:385] T cc72a37db98e41c5994d781924c1e00e: removed 13 log segments from log reader
I20260812 06:18:19.881325 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000027 (ops 131-135)
I20260812 06:18:19.881353 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000028 (ops 136-140)
I20260812 06:18:19.881417 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000029 (ops 141-145)
I20260812 06:18:19.881457 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000030 (ops 146-150)
I20260812 06:18:19.881511 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000031 (ops 151-154)
I20260812 06:18:19.881554 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000032 (ops 155-159)
I20260812 06:18:19.881595 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000033 (ops 160-164)
I20260812 06:18:19.881633 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000034 (ops 165-169)
I20260812 06:18:19.881673 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000035 (ops 170-174)
I20260812 06:18:19.881711 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000036 (ops 175-179)
I20260812 06:18:19.881749 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000037 (ops 180-184)
I20260812 06:18:19.881788 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000038 (ops 185-189)
I20260812 06:18:19.881830 30526 log.cc:1079] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: Deleting log segment in path: /tmp/dist-test-taskQX0R0k/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515489089486-30199-0/minicluster-data/ts-0-root/wals/cc72a37db98e41c5994d781924c1e00e/wal-000000039 (ops 190-194)
I20260812 06:18:19.909688 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: LogGCOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:19.910161 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling UndoDeltaBlockGCOp(cc72a37db98e41c5994d781924c1e00e): 493 bytes on disk
I20260812 06:18:19.910605 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: UndoDeltaBlockGCOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:18:19.911315 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=7.149875
I20260812 06:18:19.947022 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.036s	user 0.007s	sys 0.026s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":10756,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:19.947691 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e): perf score=2.188937
I20260812 06:18:19.957777 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: FlushDeltaMemStoresOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3663,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:19.958393 30597 maintenance_manager.cc:419] P 0bfbdc902f5e4cfd84f6268b9dc2e971: Scheduling MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e): perf score=1.000000
I20260812 06:18:19.999388 30199 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.094s	user 1.863s	sys 0.222s
I20260812 06:18:20.096406 30199 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.097s	user 0.001s	sys 0.000s
I20260812 06:18:20.097015 30199 tablet_server.cc:179] TabletServer@127.29.125.193:0 shutting down...
I20260812 06:18:20.154944 30526 maintenance_manager.cc:643] P 0bfbdc902f5e4cfd84f6268b9dc2e971: MajorDeltaCompactionOp(cc72a37db98e41c5994d781924c1e00e) complete. Timing: real 0.196s	user 0.117s	sys 0.079s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979734,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":490,"lbm_read_time_us":15203,"lbm_reads_lt_1ms":770,"lbm_write_time_us":32815,"lbm_writes_lt_1ms":743,"mutex_wait_us":84,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12928,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:18:20.155611 30199 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:20.155824 30199 tablet_replica.cc:333] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971: stopping tablet replica
I20260812 06:18:20.155977 30199 raft_consensus.cc:2243] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:20.156177 30199 raft_consensus.cc:2272] T cc72a37db98e41c5994d781924c1e00e P 0bfbdc902f5e4cfd84f6268b9dc2e971 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:20.162191 30199 tablet_server.cc:196] TabletServer@127.29.125.193:0 shutdown complete.
I20260812 06:18:20.212841 30199 master.cc:562] Master@127.29.125.254:42567 shutting down...
I20260812 06:18:20.216681 30199 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:20.216888 30199 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:20.216979 30199 tablet_replica.cc:333] T 00000000000000000000000000000000 P 448a706d1f604745a3ef4572d25cc8e3: stopping tablet replica
I20260812 06:18:20.229238 30199 master.cc:584] Master@127.29.125.254:42567 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5626 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11224 ms total)

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