[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:56.452888 19944 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.122.62:34237
I20260812 06:19:56.453897 19944 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:56.454517 19944 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:56.460873 19954 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:56.460914 19944 server_base.cc:1061] running on GCE node
W20260812 06:19:56.460882 19959 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:56.461227 19953 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:56.461755 19944 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:56.461869 19944 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:56.461930 19944 hybrid_clock.cc:648] HybridClock initialized: now 1786515596461928 us; error 0 us; skew 500 ppm
I20260812 06:19:56.463665 19944 webserver.cc:533] Webserver started at http://127.19.122.62:46443/ using document root <none> and password file <none>
I20260812 06:19:56.464183 19944 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:56.464269 19944 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:56.464519 19944 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:56.466198 19944 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/master-0-root/instance:
uuid: "903ce4360c514be593e2f3d1d4895e00"
format_stamp: "Formatted at 2026-08-12 06:19:56 on dist-test-slave-w4v5"
I20260812 06:19:56.469575 19944 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:56.471648 19965 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:56.472642 19944 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:56.472772 19944 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/master-0-root
uuid: "903ce4360c514be593e2f3d1d4895e00"
format_stamp: "Formatted at 2026-08-12 06:19:56 on dist-test-slave-w4v5"
I20260812 06:19:56.472873 19944 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:56.488722 19944 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:56.489400 19944 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:56.489600 19944 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:56.498209 19944 rpc_server.cc:307] RPC server started. Bound to: 127.19.122.62:34237
I20260812 06:19:56.498219 20066 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.122.62:34237 every 8 connection(s)
I20260812 06:19:56.500479 20068 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:56.505836 20068 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00: Bootstrap starting.
I20260812 06:19:56.508224 20068 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:56.509109 20068 log.cc:826] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:56.510878 20068 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00: No bootstrap required, opened a new log
I20260812 06:19:56.513626 20068 raft_consensus.cc:359] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "903ce4360c514be593e2f3d1d4895e00" member_type: VOTER }
I20260812 06:19:56.513787 20068 raft_consensus.cc:385] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:56.513906 20068 raft_consensus.cc:740] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 903ce4360c514be593e2f3d1d4895e00, State: Initialized, Role: FOLLOWER
I20260812 06:19:56.514483 20068 consensus_queue.cc:260] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [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: "903ce4360c514be593e2f3d1d4895e00" member_type: VOTER }
I20260812 06:19:56.514647 20068 raft_consensus.cc:399] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:56.514719 20068 raft_consensus.cc:493] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:56.514861 20068 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:56.515681 20068 raft_consensus.cc:515] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "903ce4360c514be593e2f3d1d4895e00" member_type: VOTER }
I20260812 06:19:56.516111 20068 leader_election.cc:304] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [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: 903ce4360c514be593e2f3d1d4895e00; no voters: 
I20260812 06:19:56.516444 20068 leader_election.cc:290] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:56.516569 20072 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:56.516798 20072 raft_consensus.cc:697] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [term 1 LEADER]: Becoming Leader. State: Replica: 903ce4360c514be593e2f3d1d4895e00, State: Running, Role: LEADER
I20260812 06:19:56.517241 20072 consensus_queue.cc:237] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [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: "903ce4360c514be593e2f3d1d4895e00" member_type: VOTER }
I20260812 06:19:56.517472 20068 sys_catalog.cc:565] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:56.519284 20074 sys_catalog.cc:455] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 903ce4360c514be593e2f3d1d4895e00. Latest consensus state: current_term: 1 leader_uuid: "903ce4360c514be593e2f3d1d4895e00" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "903ce4360c514be593e2f3d1d4895e00" member_type: VOTER } }
I20260812 06:19:56.519407 20074 sys_catalog.cc:458] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:56.519779 19944 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:56.520038 20104 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:56.520148 20073 sys_catalog.cc:455] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "903ce4360c514be593e2f3d1d4895e00" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "903ce4360c514be593e2f3d1d4895e00" member_type: VOTER } }
I20260812 06:19:56.520239 20073 sys_catalog.cc:458] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:56.522506 20104 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:56.527974 20104 catalog_manager.cc:1383] Generated new cluster ID: 453080854a8c44cabc7d41f52717465f
I20260812 06:19:56.528046 20104 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:56.563139 20104 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:56.564352 20104 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:56.577083 20104 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00: Generated new TSK 0
I20260812 06:19:56.577929 20104 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:56.584640 19944 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:56.587667 20114 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:56.587663 20113 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:56.587999 20118 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:56.588163 19944 server_base.cc:1061] running on GCE node
I20260812 06:19:56.588330 19944 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:56.588375 19944 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:56.588398 19944 hybrid_clock.cc:648] HybridClock initialized: now 1786515596588398 us; error 0 us; skew 500 ppm
I20260812 06:19:56.589362 19944 webserver.cc:533] Webserver started at http://127.19.122.1:45941/ using document root <none> and password file <none>
I20260812 06:19:56.589525 19944 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:56.589581 19944 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:56.589696 19944 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:56.590140 19944 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/instance:
uuid: "bb175147596b4a6882551f20da11f41e"
format_stamp: "Formatted at 2026-08-12 06:19:56 on dist-test-slave-w4v5"
I20260812 06:19:56.592054 19944 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:56.593148 20125 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:56.593397 19944 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:56.593474 19944 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root
uuid: "bb175147596b4a6882551f20da11f41e"
format_stamp: "Formatted at 2026-08-12 06:19:56 on dist-test-slave-w4v5"
I20260812 06:19:56.593539 19944 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:56.622169 19944 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:56.622682 19944 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:56.623268 19944 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:56.624255 19944 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:56.624321 19944 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:56.624379 19944 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:56.624410 19944 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:56.631582 19944 rpc_server.cc:307] RPC server started. Bound to: 127.19.122.1:46195
I20260812 06:19:56.631649 20229 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.122.1:46195 every 8 connection(s)
I20260812 06:19:56.646195 20230 heartbeater.cc:344] Connected to a master server at 127.19.122.62:34237
I20260812 06:19:56.646454 20230 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:56.646944 20230 heartbeater.cc:507] Master 127.19.122.62:34237 requested a full tablet report, sending...
I20260812 06:19:56.648535 19996 ts_manager.cc:194] Registered new tserver with Master: bb175147596b4a6882551f20da11f41e (127.19.122.1:46195)
I20260812 06:19:56.649067 19944 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016760025s
I20260812 06:19:56.650146 19996 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44418
I20260812 06:19:56.662498 19996 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44430:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:56.679132 20158 tablet_service.cc:1511] Processing CreateTablet for tablet 902ab2fd03634c98a1b93c3701264b49 (DEFAULT_TABLE table=heavy-update-compaction-test [id=5ff4cd8b069d4f31bcb7e13868a3ac21]), partition=
I20260812 06:19:56.679589 20158 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 902ab2fd03634c98a1b93c3701264b49. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:56.682400 20249 tablet_bootstrap.cc:492] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Bootstrap starting.
I20260812 06:19:56.683565 20249 tablet_bootstrap.cc:654] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:56.687862 20249 tablet_bootstrap.cc:492] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: No bootstrap required, opened a new log
I20260812 06:19:56.687978 20249 ts_tablet_manager.cc:1403] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Time spent bootstrapping tablet: real 0.006s	user 0.002s	sys 0.000s
I20260812 06:19:56.688531 20249 raft_consensus.cc:359] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bb175147596b4a6882551f20da11f41e" member_type: VOTER last_known_addr { host: "127.19.122.1" port: 46195 } }
I20260812 06:19:56.688647 20249 raft_consensus.cc:385] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:56.688680 20249 raft_consensus.cc:740] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bb175147596b4a6882551f20da11f41e, State: Initialized, Role: FOLLOWER
I20260812 06:19:56.688812 20249 consensus_queue.cc:260] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e [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: "bb175147596b4a6882551f20da11f41e" member_type: VOTER last_known_addr { host: "127.19.122.1" port: 46195 } }
I20260812 06:19:56.688908 20249 raft_consensus.cc:399] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:56.688944 20249 raft_consensus.cc:493] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:56.688985 20249 raft_consensus.cc:3060] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:56.689967 20249 raft_consensus.cc:515] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bb175147596b4a6882551f20da11f41e" member_type: VOTER last_known_addr { host: "127.19.122.1" port: 46195 } }
I20260812 06:19:56.690114 20249 leader_election.cc:304] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e [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: bb175147596b4a6882551f20da11f41e; no voters: 
I20260812 06:19:56.690313 20249 leader_election.cc:290] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:56.690451 20253 raft_consensus.cc:2804] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:56.690659 20249 ts_tablet_manager.cc:1434] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Time spent starting tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:56.690670 20253 raft_consensus.cc:697] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e [term 1 LEADER]: Becoming Leader. State: Replica: bb175147596b4a6882551f20da11f41e, State: Running, Role: LEADER
I20260812 06:19:56.691061 20230 heartbeater.cc:499] Master 127.19.122.62:34237 was elected leader, sending a full tablet report...
I20260812 06:19:56.690865 20253 consensus_queue.cc:237] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e [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: "bb175147596b4a6882551f20da11f41e" member_type: VOTER last_known_addr { host: "127.19.122.1" port: 46195 } }
I20260812 06:19:56.694293 19996 catalog_manager.cc:5719] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e reported cstate change: term changed from 0 to 1, leader changed from <none> to bb175147596b4a6882551f20da11f41e (127.19.122.1). New cstate: current_term: 1 leader_uuid: "bb175147596b4a6882551f20da11f41e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bb175147596b4a6882551f20da11f41e" member_type: VOTER last_known_addr { host: "127.19.122.1" port: 46195 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:56.768778 19944 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.064s	user 0.028s	sys 0.001s
I20260812 06:19:56.889148 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushMRSOp(902ab2fd03634c98a1b93c3701264b49): perf score=15.086190
I20260812 06:19:57.066200 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushMRSOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.177s	user 0.130s	sys 0.040s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":279,"delete_count":0,"dirs.queue_time_us":40,"dirs.run_cpu_time_us":182,"dirs.run_wall_time_us":818,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43511,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":131,"threads_started":1,"update_count":1500}
I20260812 06:19:57.067541 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling LogGCOp(902ab2fd03634c98a1b93c3701264b49): free 8725963 bytes of WAL
I20260812 06:19:57.067915 20133 log_reader.cc:385] T 902ab2fd03634c98a1b93c3701264b49: removed 1 log segments from log reader
I20260812 06:19:57.068025 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000001 (ops 1-6)
I20260812 06:19:57.070686 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: LogGCOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:57.071062 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:19:57.090662 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.019s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7014,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.091301 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:19:57.260298 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.169s	user 0.136s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":655,"lbm_read_time_us":10252,"lbm_reads_lt_1ms":464,"lbm_write_time_us":31995,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":363,"threads_started":5,"update_count":2000}
I20260812 06:19:57.264640 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling UndoDeltaBlockGCOp(902ab2fd03634c98a1b93c3701264b49): 12308958 bytes on disk
I20260812 06:19:57.266001 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: UndoDeltaBlockGCOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:57.266556 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=11.118625
I20260812 06:19:57.305951 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.039s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17285,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:57.306581 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:19:57.333029 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.026s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5327,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:57.333565 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:19:57.347488 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.014s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5452,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.348019 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:19:57.519007 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.171s	user 0.132s	sys 0.034s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":296,"lbm_read_time_us":11098,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34618,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:19:57.519788 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=14.095187
I20260812 06:19:57.572598 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.053s	user 0.039s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22176,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.573076 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:19:57.583503 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3980,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.583891 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:19:57.758220 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.174s	user 0.141s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":338,"lbm_read_time_us":11468,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34153,"lbm_writes_lt_1ms":543,"mutex_wait_us":92,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:19:57.758744 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=14.095187
I20260812 06:19:57.824397 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.065s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23566,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.824937 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:19:57.839636 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.014s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5598,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.840236 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:19:58.028487 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.188s	user 0.155s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":521,"lbm_read_time_us":12580,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35218,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2500}
I20260812 06:19:58.029013 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=14.095187
I20260812 06:19:58.082947 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.054s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24612,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.083534 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:19:58.097791 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.014s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5623,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.098235 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:19:58.282811 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.184s	user 0.152s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1983,"lbm_read_time_us":13104,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32547,"lbm_writes_lt_1ms":543,"mutex_wait_us":529,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:19:58.283386 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=14.095187
I20260812 06:19:58.345399 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.062s	user 0.022s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23348,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.345927 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:19:58.363585 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5619,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.364099 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushMRSOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:19:58.401917 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushMRSOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.038s	user 0.032s	sys 0.004s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":279,"dirs.run_wall_time_us":1382,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1965,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:58.402853 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling LogGCOp(902ab2fd03634c98a1b93c3701264b49): free 124257228 bytes of WAL
I20260812 06:19:58.403064 20133 log_reader.cc:385] T 902ab2fd03634c98a1b93c3701264b49: removed 12 log segments from log reader
I20260812 06:19:58.403153 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000002 (ops 7-11)
I20260812 06:19:58.403198 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000003 (ops 12-16)
I20260812 06:19:58.403234 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000004 (ops 17-21)
I20260812 06:19:58.403267 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000005 (ops 22-26)
I20260812 06:19:58.403297 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000006 (ops 27-31)
I20260812 06:19:58.403331 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000007 (ops 32-36)
I20260812 06:19:58.403362 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000008 (ops 37-40)
I20260812 06:19:58.403390 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000009 (ops 41-45)
I20260812 06:19:58.403421 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000010 (ops 46-50)
I20260812 06:19:58.403450 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000011 (ops 51-55)
I20260812 06:19:58.403483 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000012 (ops 56-60)
I20260812 06:19:58.403517 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000013 (ops 61-65)
I20260812 06:19:58.434252 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: LogGCOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:58.434666 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=3.181125
I20260812 06:19:58.447391 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":5169287,"delete_count":0,"lbm_write_time_us":4980,"lbm_writes_lt_1ms":129,"reinsert_count":0,"update_count":630}
I20260812 06:19:58.447808 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.196750
I20260812 06:19:58.456275 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.008s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3036005,"delete_count":0,"lbm_write_time_us":3254,"lbm_writes_lt_1ms":77,"reinsert_count":0,"update_count":370}
I20260812 06:19:58.456696 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling UndoDeltaBlockGCOp(902ab2fd03634c98a1b93c3701264b49): 462 bytes on disk
I20260812 06:19:58.457077 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: UndoDeltaBlockGCOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:19:58.457479 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:19:58.703243 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.246s	user 0.161s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938759,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":4325,"dirs.run_cpu_time_us":530,"dirs.run_wall_time_us":4091,"lbm_read_time_us":16383,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40660,"lbm_writes_lt_1ms":743,"mutex_wait_us":3624,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6144,"thread_start_us":124,"threads_started":1,"update_count":3500}
I20260812 06:19:58.703958 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=14.095187
I20260812 06:19:58.769503 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.065s	user 0.031s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22599,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.770012 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:19:58.780834 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4158,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.781332 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:19:58.944469 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.163s	user 0.118s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":579,"lbm_read_time_us":11669,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27898,"lbm_writes_lt_1ms":543,"mutex_wait_us":275,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:58.948446 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=10.126437
I20260812 06:19:59.003398 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.054s	user 0.036s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16795,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.003914 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:19:59.020179 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6005,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.020718 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:19:59.168706 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.148s	user 0.107s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":155,"lbm_read_time_us":12167,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23497,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:19:59.169708 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=7.149875
I20260812 06:19:59.197480 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.028s	user 0.015s	sys 0.007s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11343,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":212,"reinsert_count":0,"update_count":1050}
I20260812 06:19:59.197984 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:19:59.210103 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4537,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:59.210651 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:19:59.326188 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.115s	user 0.083s	sys 0.028s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":244,"dirs.run_cpu_time_us":432,"dirs.run_wall_time_us":2999,"lbm_read_time_us":8964,"lbm_reads_lt_1ms":372,"lbm_write_time_us":20313,"lbm_writes_lt_1ms":343,"mutex_wait_us":33,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":1500}
I20260812 06:19:59.326920 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=6.157687
I20260812 06:19:59.369803 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.043s	user 0.024s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":14665,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":202,"reinsert_count":0,"update_count":1000}
I20260812 06:19:59.370419 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:19:59.384974 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5664,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.385452 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:19:59.501323 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.116s	user 0.090s	sys 0.025s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528900,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":771,"lbm_read_time_us":7772,"lbm_reads_lt_1ms":372,"lbm_write_time_us":21314,"lbm_writes_lt_1ms":343,"mutex_wait_us":286,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":1500}
I20260812 06:19:59.501782 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=10.126437
I20260812 06:19:59.546033 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.044s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16949,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.546548 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:19:59.564038 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6418,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.564651 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:19:59.709794 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.145s	user 0.116s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":265,"lbm_read_time_us":8846,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27779,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3387136,"update_count":2000}
I20260812 06:19:59.712041 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=10.126437
I20260812 06:19:59.770709 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.058s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18636,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.771306 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:19:59.786262 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5655,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.786890 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:19:59.935488 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.148s	user 0.121s	sys 0.013s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":243,"lbm_read_time_us":11926,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23909,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.936187 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=10.126437
I20260812 06:19:59.986754 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.050s	user 0.030s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21250,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.987339 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:19:59.998474 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4626,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.998903 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushMRSOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:20:00.031416 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushMRSOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.032s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":149,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1821,"drs_written":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1832,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:00.032173 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling LogGCOp(902ab2fd03634c98a1b93c3701264b49): free 120553339 bytes of WAL
I20260812 06:20:00.032429 20133 log_reader.cc:385] T 902ab2fd03634c98a1b93c3701264b49: removed 12 log segments from log reader
I20260812 06:20:00.032498 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000014 (ops 66-70)
I20260812 06:20:00.032557 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000015 (ops 71-75)
I20260812 06:20:00.032608 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000016 (ops 76-80)
I20260812 06:20:00.032653 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000017 (ops 81-85)
I20260812 06:20:00.032702 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000018 (ops 86-90)
I20260812 06:20:00.032755 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000019 (ops 91-95)
I20260812 06:20:00.032805 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000020 (ops 96-100)
I20260812 06:20:00.032857 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000021 (ops 101-104)
I20260812 06:20:00.032902 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000022 (ops 105-109)
I20260812 06:20:00.032946 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000023 (ops 110-114)
I20260812 06:20:00.032990 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000024 (ops 115-118)
I20260812 06:20:00.033035 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000025 (ops 119-123)
I20260812 06:20:00.060173 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: LogGCOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:00.060575 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=3.181125
I20260812 06:20:00.080845 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.020s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4953,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:00.081364 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:20:00.095463 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.014s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5432,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:00.095973 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:20:00.277740 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.181s	user 0.140s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836361,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":134,"lbm_read_time_us":13437,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38562,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":268,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10752,"thread_start_us":104,"threads_started":1,"update_count":3000}
I20260812 06:20:00.278384 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling UndoDeltaBlockGCOp(902ab2fd03634c98a1b93c3701264b49): 462 bytes on disk
I20260812 06:20:00.282368 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: UndoDeltaBlockGCOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.001s	user 0.001s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":496,"lbm_reads_lt_1ms":4}
I20260812 06:20:00.283345 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=14.095187
I20260812 06:20:00.330920 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.047s	user 0.030s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22498,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.331722 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:20:00.350329 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.018s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6096,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.351023 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:20:00.527311 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.176s	user 0.139s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":174,"lbm_read_time_us":13021,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32180,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":119808,"update_count":2500}
I20260812 06:20:00.527908 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=14.095187
I20260812 06:20:00.581336 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.053s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409953,"delete_count":0,"lbm_write_time_us":22837,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.581817 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:20:00.750892 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.169s	user 0.112s	sys 0.037s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631244,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":971,"lbm_read_time_us":9749,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24667,"lbm_writes_lt_1ms":443,"mutex_wait_us":324,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.751372 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=14.095187
I20260812 06:20:00.808478 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.057s	user 0.033s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24217,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.808971 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:20:00.824635 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.015s	user 0.008s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5779,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.825335 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:20:01.042745 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.217s	user 0.145s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":301,"lbm_read_time_us":11004,"lbm_reads_lt_1ms":572,"lbm_write_time_us":39616,"lbm_writes_lt_1ms":543,"mutex_wait_us":92,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2500}
I20260812 06:20:01.043537 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=11.118625
I20260812 06:20:01.093803 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.050s	user 0.031s	sys 0.016s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":21594,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:01.094367 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:20:01.130683 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.036s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5652,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.131237 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:20:01.145956 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5650,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.146605 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:20:01.303185 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.156s	user 0.102s	sys 0.051s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733833,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":956,"lbm_read_time_us":10185,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29060,"lbm_writes_lt_1ms":543,"mutex_wait_us":275,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:01.304118 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=11.118625
I20260812 06:20:01.337769 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.033s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14107,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:01.338469 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:20:01.363415 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.025s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5856,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.363919 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:20:01.374243 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4025,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.374714 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:20:01.528327 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.153s	user 0.116s	sys 0.035s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":975,"lbm_read_time_us":11571,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30353,"lbm_writes_lt_1ms":543,"mutex_wait_us":261,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:20:01.529067 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=11.118625
I20260812 06:20:01.568728 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.039s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16872,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:01.569633 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:20:01.595678 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.026s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4734,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.596161 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:20:01.611233 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.015s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5786,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.611786 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushMRSOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:20:01.646926 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushMRSOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.035s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1370,"drs_written":1,"lbm_read_time_us":115,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2129,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:01.647709 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling LogGCOp(902ab2fd03634c98a1b93c3701264b49): free 124710539 bytes of WAL
I20260812 06:20:01.647935 20133 log_reader.cc:385] T 902ab2fd03634c98a1b93c3701264b49: removed 12 log segments from log reader
I20260812 06:20:01.647979 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000026 (ops 124-128)
I20260812 06:20:01.648007 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000027 (ops 129-133)
I20260812 06:20:01.648072 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000028 (ops 134-138)
I20260812 06:20:01.648121 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000029 (ops 139-143)
I20260812 06:20:01.648164 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000030 (ops 144-148)
I20260812 06:20:01.648190 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000031 (ops 149-153)
I20260812 06:20:01.648227 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000032 (ops 154-158)
I20260812 06:20:01.648269 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000033 (ops 159-163)
I20260812 06:20:01.648310 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000034 (ops 164-168)
I20260812 06:20:01.648350 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000035 (ops 169-173)
I20260812 06:20:01.648399 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000036 (ops 174-178)
I20260812 06:20:01.648439 20133 log.cc:1079] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/902ab2fd03634c98a1b93c3701264b49/wal-000000037 (ops 179-183)
I20260812 06:20:01.674963 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: LogGCOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.027s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:01.675369 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=3.181125
I20260812 06:20:01.693518 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.018s	user 0.002s	sys 0.014s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7466,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:01.693954 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling UndoDeltaBlockGCOp(902ab2fd03634c98a1b93c3701264b49): 481 bytes on disk
I20260812 06:20:01.694351 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: UndoDeltaBlockGCOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:20:01.694964 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:20:01.713969 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.019s	user 0.005s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3995,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.714537 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:20:01.946482 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.232s	user 0.148s	sys 0.075s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32938884,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":536,"lbm_read_time_us":16367,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39446,"lbm_writes_lt_1ms":743,"mutex_wait_us":46,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12416,"thread_start_us":89,"threads_started":1,"update_count":3500}
I20260812 06:20:01.947378 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=18.063937
I20260812 06:20:01.993976 19944 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.225s	user 1.906s	sys 0.140s
I20260812 06:20:02.010469 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.063s	user 0.033s	sys 0.028s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":32842,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":500,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:20:02.010959 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49): perf score=2.188937
I20260812 06:20:02.021340 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: FlushDeltaMemStoresOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4483,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.021791 20231 maintenance_manager.cc:419] P bb175147596b4a6882551f20da11f41e: Scheduling MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49): perf score=1.000000
I20260812 06:20:02.047140 19944 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.052s	user 0.004s	sys 0.000s
I20260812 06:20:02.047785 19944 tablet_server.cc:179] TabletServer@127.19.122.1:0 shutting down...
I20260812 06:20:02.181700 20133 maintenance_manager.cc:643] P bb175147596b4a6882551f20da11f41e: MajorDeltaCompactionOp(902ab2fd03634c98a1b93c3701264b49) complete. Timing: real 0.160s	user 0.115s	sys 0.044s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4221425,"cfile_cache_miss":602,"cfile_cache_miss_bytes":24614712,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":604,"lbm_read_time_us":10560,"lbm_reads_lt_1ms":618,"lbm_write_time_us":28168,"lbm_writes_lt_1ms":643,"mutex_wait_us":91,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":3000}
I20260812 06:20:02.182405 19944 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:02.182860 19944 tablet_replica.cc:333] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e: stopping tablet replica
I20260812 06:20:02.183156 19944 raft_consensus.cc:2243] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:02.183418 19944 raft_consensus.cc:2272] T 902ab2fd03634c98a1b93c3701264b49 P bb175147596b4a6882551f20da11f41e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:02.200337 19944 tablet_server.cc:196] TabletServer@127.19.122.1:0 shutdown complete.
I20260812 06:20:02.234644 19944 master.cc:562] Master@127.19.122.62:34237 shutting down...
I20260812 06:20:02.238612 19944 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:02.238823 19944 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:02.238912 19944 tablet_replica.cc:333] T 00000000000000000000000000000000 P 903ce4360c514be593e2f3d1d4895e00: stopping tablet replica
I20260812 06:20:02.252314 19944 master.cc:584] Master@127.19.122.62:34237 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5890 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:02.355548 19944 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.122.62:33221
I20260812 06:20:02.355991 19944 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:02.358747 20299 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:20:02.358896 20297 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:20:02.358947 20301 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:20:02.358961 19944 server_base.cc:1061] running on GCE node
I20260812 06:20:02.359293 19944 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:02.359338 19944 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:20:02.359354 19944 hybrid_clock.cc:648] HybridClock initialized: now 1786515602359353 us; error 0 us; skew 500 ppm
I20260812 06:20:02.360183 19944 webserver.cc:533] Webserver started at http://127.19.122.62:41227/ using document root <none> and password file <none>
I20260812 06:20:02.360317 19944 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:02.360360 19944 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:02.360417 19944 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:02.360788 19944 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/master-0-root/instance:
uuid: "e85267bfd31d44a5b5c5d11ce5eceeec"
format_stamp: "Formatted at 2026-08-12 06:20:02 on dist-test-slave-w4v5"
I20260812 06:20:02.362316 19944 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:02.363309 20308 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:20:02.363535 19944 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:02.363623 19944 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/master-0-root
uuid: "e85267bfd31d44a5b5c5d11ce5eceeec"
format_stamp: "Formatted at 2026-08-12 06:20:02 on dist-test-slave-w4v5"
I20260812 06:20:02.363723 19944 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-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:20:02.373029 19944 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:02.373410 19944 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:02.377758 19944 rpc_server.cc:307] RPC server started. Bound to: 127.19.122.62:33221
I20260812 06:20:02.377790 20391 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.122.62:33221 every 8 connection(s)
I20260812 06:20:02.378572 20393 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:20:02.380456 20393 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec: Bootstrap starting.
I20260812 06:20:02.381318 20393 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:02.382308 20393 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec: No bootstrap required, opened a new log
I20260812 06:20:02.382710 20393 raft_consensus.cc:359] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e85267bfd31d44a5b5c5d11ce5eceeec" member_type: VOTER }
I20260812 06:20:02.382797 20393 raft_consensus.cc:385] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:02.382818 20393 raft_consensus.cc:740] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e85267bfd31d44a5b5c5d11ce5eceeec, State: Initialized, Role: FOLLOWER
I20260812 06:20:02.383011 20393 consensus_queue.cc:260] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [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: "e85267bfd31d44a5b5c5d11ce5eceeec" member_type: VOTER }
I20260812 06:20:02.383131 20393 raft_consensus.cc:399] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:02.383178 20393 raft_consensus.cc:493] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:02.383210 20393 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:02.383831 20393 raft_consensus.cc:515] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e85267bfd31d44a5b5c5d11ce5eceeec" member_type: VOTER }
I20260812 06:20:02.383941 20393 leader_election.cc:304] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [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: e85267bfd31d44a5b5c5d11ce5eceeec; no voters: 
I20260812 06:20:02.384078 20393 leader_election.cc:290] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:02.384209 20396 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:02.384418 20396 raft_consensus.cc:697] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [term 1 LEADER]: Becoming Leader. State: Replica: e85267bfd31d44a5b5c5d11ce5eceeec, State: Running, Role: LEADER
I20260812 06:20:02.384512 20393 sys_catalog.cc:565] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:02.384557 20396 consensus_queue.cc:237] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [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: "e85267bfd31d44a5b5c5d11ce5eceeec" member_type: VOTER }
I20260812 06:20:02.384991 20397 sys_catalog.cc:455] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e85267bfd31d44a5b5c5d11ce5eceeec" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e85267bfd31d44a5b5c5d11ce5eceeec" member_type: VOTER } }
I20260812 06:20:02.385025 20398 sys_catalog.cc:455] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [sys.catalog]: SysCatalogTable state changed. Reason: New leader e85267bfd31d44a5b5c5d11ce5eceeec. Latest consensus state: current_term: 1 leader_uuid: "e85267bfd31d44a5b5c5d11ce5eceeec" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e85267bfd31d44a5b5c5d11ce5eceeec" member_type: VOTER } }
I20260812 06:20:02.385083 20397 sys_catalog.cc:458] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:02.385108 20398 sys_catalog.cc:458] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:02.385330 20403 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:02.386199 20403 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:02.386332 19944 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:02.387980 20403 catalog_manager.cc:1383] Generated new cluster ID: c55ff567034640ab9e04d997c3cf106a
I20260812 06:20:02.388041 20403 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:02.397281 20403 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:02.397831 20403 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:02.403096 20403 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec: Generated new TSK 0
I20260812 06:20:02.403242 20403 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:02.418829 19944 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:02.421105 20422 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:20:02.421180 20424 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:20:02.421239 19944 server_base.cc:1061] running on GCE node
W20260812 06:20:02.421202 20421 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:20:02.421636 19944 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:02.421687 19944 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:20:02.421703 19944 hybrid_clock.cc:648] HybridClock initialized: now 1786515602421704 us; error 0 us; skew 500 ppm
I20260812 06:20:02.422730 19944 webserver.cc:533] Webserver started at http://127.19.122.1:41971/ using document root <none> and password file <none>
I20260812 06:20:02.422914 19944 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:02.422963 19944 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:02.423043 19944 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:02.423509 19944 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/instance:
uuid: "6b064176488f43689e6e49cc242014ef"
format_stamp: "Formatted at 2026-08-12 06:20:02 on dist-test-slave-w4v5"
I20260812 06:20:02.425135 19944 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:02.426415 20435 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:20:02.426651 19944 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:02.426754 19944 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root
uuid: "6b064176488f43689e6e49cc242014ef"
format_stamp: "Formatted at 2026-08-12 06:20:02 on dist-test-slave-w4v5"
I20260812 06:20:02.426848 19944 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-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:20:02.436439 19944 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:02.436842 19944 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:02.437165 19944 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:02.437634 19944 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:02.437726 19944 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:02.437808 19944 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:02.437857 19944 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:02.442077 19944 rpc_server.cc:307] RPC server started. Bound to: 127.19.122.1:33239
I20260812 06:20:02.442113 20550 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.122.1:33239 every 8 connection(s)
I20260812 06:20:02.450690 20552 heartbeater.cc:344] Connected to a master server at 127.19.122.62:33221
I20260812 06:20:02.450842 20552 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:02.451162 20552 heartbeater.cc:507] Master 127.19.122.62:33221 requested a full tablet report, sending...
I20260812 06:20:02.451844 20337 ts_manager.cc:194] Registered new tserver with Master: 6b064176488f43689e6e49cc242014ef (127.19.122.1:33239)
I20260812 06:20:02.452407 19944 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009925081s
I20260812 06:20:02.452627 20337 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45800
I20260812 06:20:02.459899 20337 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45812:
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:20:02.468947 20487 tablet_service.cc:1511] Processing CreateTablet for tablet ce31a6a6792741359ea9077b28cdb069 (DEFAULT_TABLE table=heavy-update-compaction-test [id=a578e7d378844cc380ab52a9cb5e385b]), partition=
I20260812 06:20:02.469265 20487 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ce31a6a6792741359ea9077b28cdb069. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:02.471390 20571 tablet_bootstrap.cc:492] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Bootstrap starting.
I20260812 06:20:02.472321 20571 tablet_bootstrap.cc:654] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:02.473400 20571 tablet_bootstrap.cc:492] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: No bootstrap required, opened a new log
I20260812 06:20:02.473482 20571 ts_tablet_manager.cc:1403] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:02.473891 20571 raft_consensus.cc:359] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6b064176488f43689e6e49cc242014ef" member_type: VOTER last_known_addr { host: "127.19.122.1" port: 33239 } }
I20260812 06:20:02.473980 20571 raft_consensus.cc:385] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:02.474004 20571 raft_consensus.cc:740] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6b064176488f43689e6e49cc242014ef, State: Initialized, Role: FOLLOWER
I20260812 06:20:02.474113 20571 consensus_queue.cc:260] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef [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: "6b064176488f43689e6e49cc242014ef" member_type: VOTER last_known_addr { host: "127.19.122.1" port: 33239 } }
I20260812 06:20:02.474227 20571 raft_consensus.cc:399] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:02.474284 20571 raft_consensus.cc:493] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:02.474335 20571 raft_consensus.cc:3060] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:02.475245 20571 raft_consensus.cc:515] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6b064176488f43689e6e49cc242014ef" member_type: VOTER last_known_addr { host: "127.19.122.1" port: 33239 } }
I20260812 06:20:02.475420 20571 leader_election.cc:304] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef [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: 6b064176488f43689e6e49cc242014ef; no voters: 
I20260812 06:20:02.475637 20571 leader_election.cc:290] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:02.475802 20574 raft_consensus.cc:2804] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:02.476049 20571 ts_tablet_manager.cc:1434] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:20:02.476058 20552 heartbeater.cc:499] Master 127.19.122.62:33221 was elected leader, sending a full tablet report...
I20260812 06:20:02.476037 20574 raft_consensus.cc:697] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef [term 1 LEADER]: Becoming Leader. State: Replica: 6b064176488f43689e6e49cc242014ef, State: Running, Role: LEADER
I20260812 06:20:02.476265 20574 consensus_queue.cc:237] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef [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: "6b064176488f43689e6e49cc242014ef" member_type: VOTER last_known_addr { host: "127.19.122.1" port: 33239 } }
I20260812 06:20:02.477538 20337 catalog_manager.cc:5719] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef reported cstate change: term changed from 0 to 1, leader changed from <none> to 6b064176488f43689e6e49cc242014ef (127.19.122.1). New cstate: current_term: 1 leader_uuid: "6b064176488f43689e6e49cc242014ef" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6b064176488f43689e6e49cc242014ef" member_type: VOTER last_known_addr { host: "127.19.122.1" port: 33239 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:02.544720 19944 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.060s	user 0.011s	sys 0.012s
I20260812 06:20:02.692936 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushMRSOp(ce31a6a6792741359ea9077b28cdb069): perf score=19.054940
I20260812 06:20:02.868587 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushMRSOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.175s	user 0.150s	sys 0.024s Metrics: {"bytes_written":12717735,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":99,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":737,"drs_written":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46398,"lbm_writes_lt_1ms":767,"mutex_wait_us":71,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1550}
I20260812 06:20:02.869978 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling LogGCOp(ce31a6a6792741359ea9077b28cdb069): free 20743880 bytes of WAL
I20260812 06:20:02.870280 20443 log_reader.cc:385] T ce31a6a6792741359ea9077b28cdb069: removed 2 log segments from log reader
I20260812 06:20:02.870354 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000001 (ops 1-6)
I20260812 06:20:02.870451 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000002 (ops 7-11)
I20260812 06:20:02.875645 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: LogGCOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:20:02.875998 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:02.905035 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.029s	user 0.001s	sys 0.018s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5084,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.905531 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:02.920929 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5911,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.921553 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:03.097052 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.175s	user 0.103s	sys 0.072s 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":519,"lbm_read_time_us":14167,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29443,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":361,"threads_started":5,"update_count":2500}
I20260812 06:20:03.097827 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=10.126437
I20260812 06:20:03.129974 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.032s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13780,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:03.130575 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling UndoDeltaBlockGCOp(ce31a6a6792741359ea9077b28cdb069): 16411395 bytes on disk
I20260812 06:20:03.131021 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: UndoDeltaBlockGCOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:03.131619 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:03.147361 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.015s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.147864 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:03.281164 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.133s	user 0.102s	sys 0.031s 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":179,"lbm_read_time_us":8826,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26965,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2000}
I20260812 06:20:03.281872 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=10.126437
I20260812 06:20:03.324213 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.042s	user 0.028s	sys 0.009s Metrics: {"bytes_written":12307498,"delete_count":0,"lbm_write_time_us":15692,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:03.324723 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:03.334908 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3965,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.335518 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:03.465507 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.130s	user 0.100s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672284,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":400,"lbm_read_time_us":9399,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24834,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:20:03.466320 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=10.126437
I20260812 06:20:03.512449 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.046s	user 0.032s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18018,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:20:03.512900 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:03.524155 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4180,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.524891 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:03.658286 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.133s	user 0.094s	sys 0.039s 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":934,"lbm_read_time_us":8382,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26194,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2000}
I20260812 06:20:03.658951 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=10.126437
I20260812 06:20:03.707655 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.048s	user 0.015s	sys 0.032s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17893,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:03.708190 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:03.718951 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4308,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.719512 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:03.883248 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.164s	user 0.095s	sys 0.066s 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":454,"lbm_read_time_us":11181,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25866,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2000}
I20260812 06:20:03.883955 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=11.118625
I20260812 06:20:03.921646 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.037s	user 0.021s	sys 0.014s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16818,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:03.922324 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:03.938720 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.016s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4608,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.939395 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:04.065477 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.126s	user 0.096s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":137,"lbm_read_time_us":7552,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24235,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":72832,"update_count":2000}
I20260812 06:20:04.066272 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=11.118625
I20260812 06:20:04.102401 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.036s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15800,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:04.103122 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:04.116823 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.013s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4115,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:04.117281 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushMRSOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:04.166669 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushMRSOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.049s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1296,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1608,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:04.167368 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling LogGCOp(ce31a6a6792741359ea9077b28cdb069): free 120100322 bytes of WAL
I20260812 06:20:04.167594 20443 log_reader.cc:385] T ce31a6a6792741359ea9077b28cdb069: removed 12 log segments from log reader
I20260812 06:20:04.167640 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000003 (ops 12-16)
I20260812 06:20:04.167670 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000004 (ops 17-21)
I20260812 06:20:04.167734 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000005 (ops 22-26)
I20260812 06:20:04.167776 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000006 (ops 27-30)
I20260812 06:20:04.167819 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000007 (ops 31-35)
I20260812 06:20:04.167879 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000008 (ops 36-40)
I20260812 06:20:04.167928 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000009 (ops 41-45)
I20260812 06:20:04.167968 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000010 (ops 46-50)
I20260812 06:20:04.168006 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000011 (ops 51-54)
I20260812 06:20:04.168045 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000012 (ops 55-59)
I20260812 06:20:04.168088 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000013 (ops 60-64)
I20260812 06:20:04.168128 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000014 (ops 65-68)
I20260812 06:20:04.194491 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: LogGCOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.027s	user 0.004s	sys 0.020s Metrics: {}
I20260812 06:20:04.194911 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling UndoDeltaBlockGCOp(ce31a6a6792741359ea9077b28cdb069): 472 bytes on disk
I20260812 06:20:04.195370 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: UndoDeltaBlockGCOp(ce31a6a6792741359ea9077b28cdb069) 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:20:04.195868 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=7.149875
I20260812 06:20:04.219123 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.023s	user 0.023s	sys 0.000s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9699,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:04.219626 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:04.231299 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4250,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:04.231731 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:04.457437 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.226s	user 0.174s	sys 0.037s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979735,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":335,"lbm_read_time_us":14748,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38768,"lbm_writes_lt_1ms":743,"mutex_wait_us":64,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18432,"thread_start_us":65,"threads_started":1,"update_count":3500}
I20260812 06:20:04.457973 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=18.063937
I20260812 06:20:04.527778 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.070s	user 0.037s	sys 0.030s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25275,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:20:04.528456 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:04.539420 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4399,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.539810 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:04.747126 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.207s	user 0.143s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":642,"lbm_read_time_us":15777,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33206,"lbm_writes_lt_1ms":643,"mutex_wait_us":27,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22144,"update_count":3000}
I20260812 06:20:04.747757 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=14.095187
I20260812 06:20:04.807621 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.060s	user 0.036s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22413,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.808210 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:04.820387 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4386,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.820854 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:04.996470 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.175s	user 0.120s	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":1114,"lbm_read_time_us":11950,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29057,"lbm_writes_lt_1ms":543,"mutex_wait_us":269,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:20:04.997010 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=14.095187
I20260812 06:20:05.052367 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.055s	user 0.020s	sys 0.030s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19659,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.052882 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:05.063715 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.064122 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:05.239949 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.176s	user 0.119s	sys 0.055s 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":683,"lbm_read_time_us":11900,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30604,"lbm_writes_lt_1ms":543,"mutex_wait_us":261,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:20:05.240510 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=11.118625
I20260812 06:20:05.283308 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.043s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17937,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:05.283799 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:05.315496 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.031s	user 0.014s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5303,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:05.316006 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:05.326701 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4161,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.327250 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:05.509634 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.182s	user 0.125s	sys 0.057s 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":96,"lbm_read_time_us":13030,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31186,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:20:05.510231 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=10.126437
I20260812 06:20:05.542968 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.033s	user 0.022s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13829,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:05.544555 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:05.561378 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6378,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.561851 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushMRSOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:05.586156 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushMRSOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.024s	user 0.023s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1071,"drs_written":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1416,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:05.586850 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling LogGCOp(ce31a6a6792741359ea9077b28cdb069): free 108988507 bytes of WAL
I20260812 06:20:05.587131 20443 log_reader.cc:385] T ce31a6a6792741359ea9077b28cdb069: removed 11 log segments from log reader
I20260812 06:20:05.587188 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000015 (ops 69-73)
I20260812 06:20:05.587217 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000016 (ops 74-78)
I20260812 06:20:05.587277 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000017 (ops 79-83)
I20260812 06:20:05.587307 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000018 (ops 84-88)
I20260812 06:20:05.587345 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000019 (ops 89-93)
I20260812 06:20:05.587383 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000020 (ops 94-98)
I20260812 06:20:05.587421 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000021 (ops 99-103)
I20260812 06:20:05.587459 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000022 (ops 104-108)
I20260812 06:20:05.587499 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000023 (ops 109-112)
I20260812 06:20:05.587539 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000024 (ops 113-117)
I20260812 06:20:05.587584 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000025 (ops 118-122)
I20260812 06:20:05.612141 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: LogGCOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.025s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:20:05.612589 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling UndoDeltaBlockGCOp(ce31a6a6792741359ea9077b28cdb069): 446 bytes on disk
I20260812 06:20:05.613078 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: UndoDeltaBlockGCOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:20:05.613566 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=5.165500
I20260812 06:20:05.633813 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.020s	user 0.011s	sys 0.007s Metrics: {"bytes_written":6851279,"delete_count":0,"lbm_write_time_us":8899,"lbm_writes_lt_1ms":170,"reinsert_count":0,"update_count":835}
I20260812 06:20:05.634241 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling LogGCOp(ce31a6a6792741359ea9077b28cdb069): free 12017925 bytes of WAL
I20260812 06:20:05.634447 20443 log_reader.cc:385] T ce31a6a6792741359ea9077b28cdb069: removed 1 log segments from log reader
I20260812 06:20:05.634492 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000026 (ops 123-127)
I20260812 06:20:05.636873 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: LogGCOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:05.637188 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:05.644833 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.007s	user 0.004s	sys 0.001s Metrics: {"bytes_written":1353977,"delete_count":0,"lbm_write_time_us":2010,"lbm_writes_lt_1ms":36,"reinsert_count":0,"update_count":165}
I20260812 06:20:05.648671 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:05.847747 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.199s	user 0.131s	sys 0.068s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":712,"lbm_read_time_us":14748,"lbm_reads_lt_1ms":666,"lbm_write_time_us":35493,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10752,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:20:05.848377 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=14.095187
I20260812 06:20:05.910454 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.062s	user 0.019s	sys 0.039s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22105,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.911165 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:05.938587 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.027s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5945,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.939028 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:05.953526 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5670,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.954072 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:06.161405 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.207s	user 0.115s	sys 0.091s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":944,"lbm_read_time_us":13942,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35121,"lbm_writes_lt_1ms":643,"mutex_wait_us":343,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":3000}
I20260812 06:20:06.162158 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=14.095187
I20260812 06:20:06.228389 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.066s	user 0.037s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23890,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.228827 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:06.240463 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4376,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.240944 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:06.419478 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.178s	user 0.111s	sys 0.064s 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":271,"lbm_read_time_us":11007,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32713,"lbm_writes_lt_1ms":543,"mutex_wait_us":68,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:06.419966 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=14.095187
I20260812 06:20:06.482786 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.063s	user 0.034s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20415,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.483410 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:06.500183 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.017s	user 0.005s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6423,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.500761 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:06.665199 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.164s	user 0.103s	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":292,"lbm_read_time_us":12901,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28414,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:20:06.665819 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=11.118625
I20260812 06:20:06.705567 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.040s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17149,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:06.706313 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:06.725905 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.019s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4401,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:06.726400 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:06.897143 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.171s	user 0.133s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":630,"lbm_read_time_us":11346,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25339,"lbm_writes_lt_1ms":443,"mutex_wait_us":282,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2000}
I20260812 06:20:06.897612 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=14.095187
I20260812 06:20:06.945298 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.048s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":19495,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.945820 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:06.957487 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3938,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.958125 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:07.103343 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.145s	user 0.109s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":276,"lbm_read_time_us":11834,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26716,"lbm_writes_lt_1ms":543,"mutex_wait_us":616,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:20:07.104007 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=11.118625
I20260812 06:20:07.145219 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.041s	user 0.017s	sys 0.022s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":17647,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:07.145742 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:07.166675 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.021s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5212,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:07.167200 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=2.188937
I20260812 06:20:07.177268 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3962,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.177701 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushMRSOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:07.210135 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushMRSOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":1339,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1610,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:07.210812 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling LogGCOp(ce31a6a6792741359ea9077b28cdb069): free 120553640 bytes of WAL
I20260812 06:20:07.211020 20443 log_reader.cc:385] T ce31a6a6792741359ea9077b28cdb069: removed 12 log segments from log reader
I20260812 06:20:07.211081 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000027 (ops 128-132)
I20260812 06:20:07.211154 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000028 (ops 133-137)
I20260812 06:20:07.211217 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000029 (ops 138-142)
I20260812 06:20:07.211257 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000030 (ops 143-147)
I20260812 06:20:07.211294 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000031 (ops 148-152)
I20260812 06:20:07.211330 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000032 (ops 153-156)
I20260812 06:20:07.211369 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000033 (ops 157-161)
I20260812 06:20:07.211405 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000034 (ops 162-166)
I20260812 06:20:07.211441 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000035 (ops 167-170)
I20260812 06:20:07.211477 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000036 (ops 171-175)
I20260812 06:20:07.211513 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000037 (ops 176-180)
I20260812 06:20:07.211550 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000038 (ops 181-185)
I20260812 06:20:07.237545 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: LogGCOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.027s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:20:07.237993 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=4.173312
I20260812 06:20:07.256559 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.018s	user 0.013s	sys 0.004s Metrics: {"bytes_written":6194893,"delete_count":0,"lbm_write_time_us":7878,"lbm_writes_lt_1ms":154,"reinsert_count":0,"update_count":755}
I20260812 06:20:07.257014 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling LogGCOp(ce31a6a6792741359ea9077b28cdb069): free 12017952 bytes of WAL
I20260812 06:20:07.257230 20443 log_reader.cc:385] T ce31a6a6792741359ea9077b28cdb069: removed 1 log segments from log reader
I20260812 06:20:07.257275 20443 log.cc:1079] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: Deleting log segment in path: /tmp/dist-test-tasklLjxF6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596442308-19944-0/minicluster-data/ts-0-root/wals/ce31a6a6792741359ea9077b28cdb069/wal-000000039 (ops 186-190)
I20260812 06:20:07.259531 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: LogGCOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:07.259917 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:07.277680 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.018s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2010377,"delete_count":0,"lbm_write_time_us":3241,"lbm_writes_lt_1ms":52,"reinsert_count":0,"update_count":245}
I20260812 06:20:07.278126 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069): perf score=1.000000
I20260812 06:20:07.510160 19944 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.965s	user 1.810s	sys 0.190s
I20260812 06:20:07.512480 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: MajorDeltaCompactionOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.234s	user 0.159s	sys 0.068s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979811,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":475,"lbm_read_time_us":15585,"lbm_reads_lt_1ms":767,"lbm_write_time_us":40635,"lbm_writes_lt_1ms":743,"mutex_wait_us":27,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":51712,"thread_start_us":96,"threads_started":1,"update_count":3500}
I20260812 06:20:07.513151 20553 maintenance_manager.cc:419] P 6b064176488f43689e6e49cc242014ef: Scheduling FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069): perf score=18.063937
I20260812 06:20:07.538939 19944 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.028s	user 0.001s	sys 0.000s
I20260812 06:20:07.539486 19944 tablet_server.cc:179] TabletServer@127.19.122.1:0 shutting down...
I20260812 06:20:07.579921 20443 maintenance_manager.cc:643] P 6b064176488f43689e6e49cc242014ef: FlushDeltaMemStoresOp(ce31a6a6792741359ea9077b28cdb069) complete. Timing: real 0.067s	user 0.043s	sys 0.023s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":25126,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:07.580577 19944 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:07.580854 19944 tablet_replica.cc:333] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef: stopping tablet replica
I20260812 06:20:07.581001 19944 raft_consensus.cc:2243] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:07.581179 19944 raft_consensus.cc:2272] T ce31a6a6792741359ea9077b28cdb069 P 6b064176488f43689e6e49cc242014ef [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:07.584496 19944 tablet_server.cc:196] TabletServer@127.19.122.1:0 shutdown complete.
I20260812 06:20:07.587317 19944 master.cc:562] Master@127.19.122.62:33221 shutting down...
I20260812 06:20:07.590479 19944 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:07.590610 19944 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:07.590657 19944 tablet_replica.cc:333] T 00000000000000000000000000000000 P e85267bfd31d44a5b5c5d11ce5eceeec: stopping tablet replica
I20260812 06:20:07.603572 19944 master.cc:584] Master@127.19.122.62:33221 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5347 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11238 ms total)

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