[==========] 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:10.522840 21281 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.200.126:42177
I20260812 06:19:10.523869 21281 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:10.524488 21281 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:10.531029 21291 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:10.531095 21281 server_base.cc:1061] running on GCE node
W20260812 06:19:10.531049 21293 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:10.531409 21296 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:10.531919 21281 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:10.532044 21281 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:10.532087 21281 hybrid_clock.cc:648] HybridClock initialized: now 1786515550532085 us; error 0 us; skew 500 ppm
I20260812 06:19:10.534003 21281 webserver.cc:533] Webserver started at http://127.20.200.126:38461/ using document root <none> and password file <none>
I20260812 06:19:10.534547 21281 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:10.534636 21281 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:10.534899 21281 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:10.536513 21281 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/master-0-root/instance:
uuid: "e5cc25b0d8394166a700c606697e4c04"
format_stamp: "Formatted at 2026-08-12 06:19:10 on dist-test-slave-04bb"
I20260812 06:19:10.539999 21281 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:10.542168 21306 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:10.543200 21281 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:19:10.543345 21281 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/master-0-root
uuid: "e5cc25b0d8394166a700c606697e4c04"
format_stamp: "Formatted at 2026-08-12 06:19:10 on dist-test-slave-04bb"
I20260812 06:19:10.543453 21281 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-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:10.567057 21281 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:10.567765 21281 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:10.567965 21281 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:10.575757 21281 rpc_server.cc:307] RPC server started. Bound to: 127.20.200.126:42177
I20260812 06:19:10.575767 21383 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.200.126:42177 every 8 connection(s)
I20260812 06:19:10.577978 21384 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:10.583451 21384 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04: Bootstrap starting.
I20260812 06:19:10.585934 21384 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:10.586879 21384 log.cc:826] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:10.588634 21384 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04: No bootstrap required, opened a new log
I20260812 06:19:10.591396 21384 raft_consensus.cc:359] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e5cc25b0d8394166a700c606697e4c04" member_type: VOTER }
I20260812 06:19:10.591560 21384 raft_consensus.cc:385] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:10.591634 21384 raft_consensus.cc:740] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e5cc25b0d8394166a700c606697e4c04, State: Initialized, Role: FOLLOWER
I20260812 06:19:10.592267 21384 consensus_queue.cc:260] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [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: "e5cc25b0d8394166a700c606697e4c04" member_type: VOTER }
I20260812 06:19:10.592437 21384 raft_consensus.cc:399] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:10.592515 21384 raft_consensus.cc:493] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:10.592702 21384 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:10.593525 21384 raft_consensus.cc:515] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e5cc25b0d8394166a700c606697e4c04" member_type: VOTER }
I20260812 06:19:10.594033 21384 leader_election.cc:304] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [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: e5cc25b0d8394166a700c606697e4c04; no voters: 
I20260812 06:19:10.594369 21384 leader_election.cc:290] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:10.594555 21387 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:10.594834 21387 raft_consensus.cc:697] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [term 1 LEADER]: Becoming Leader. State: Replica: e5cc25b0d8394166a700c606697e4c04, State: Running, Role: LEADER
I20260812 06:19:10.595259 21387 consensus_queue.cc:237] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [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: "e5cc25b0d8394166a700c606697e4c04" member_type: VOTER }
I20260812 06:19:10.595461 21384 sys_catalog.cc:565] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:10.597366 21389 sys_catalog.cc:455] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e5cc25b0d8394166a700c606697e4c04" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e5cc25b0d8394166a700c606697e4c04" member_type: VOTER } }
I20260812 06:19:10.597404 21390 sys_catalog.cc:455] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [sys.catalog]: SysCatalogTable state changed. Reason: New leader e5cc25b0d8394166a700c606697e4c04. Latest consensus state: current_term: 1 leader_uuid: "e5cc25b0d8394166a700c606697e4c04" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e5cc25b0d8394166a700c606697e4c04" member_type: VOTER } }
I20260812 06:19:10.597501 21389 sys_catalog.cc:458] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:10.597500 21390 sys_catalog.cc:458] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:10.597862 21408 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:10.597896 21281 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:10.600171 21408 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:10.605177 21408 catalog_manager.cc:1383] Generated new cluster ID: 5dddefae9e38411d81a355d277ab5de0
I20260812 06:19:10.605235 21408 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:10.626217 21408 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:10.627111 21408 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:10.634341 21408 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04: Generated new TSK 0
I20260812 06:19:10.635000 21408 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:10.662662 21281 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:10.665350 21414 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:10.665495 21415 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:10.665361 21417 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:10.665691 21281 server_base.cc:1061] running on GCE node
I20260812 06:19:10.665899 21281 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:10.665947 21281 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:10.665971 21281 hybrid_clock.cc:648] HybridClock initialized: now 1786515550665971 us; error 0 us; skew 500 ppm
I20260812 06:19:10.666930 21281 webserver.cc:533] Webserver started at http://127.20.200.65:42295/ using document root <none> and password file <none>
I20260812 06:19:10.667100 21281 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:10.667160 21281 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:10.667236 21281 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:10.667671 21281 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/instance:
uuid: "e6912182d6864ffe9b15edaa54ea7a50"
format_stamp: "Formatted at 2026-08-12 06:19:10 on dist-test-slave-04bb"
I20260812 06:19:10.669569 21281 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:10.670646 21425 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:10.670950 21281 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:10.671013 21281 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root
uuid: "e6912182d6864ffe9b15edaa54ea7a50"
format_stamp: "Formatted at 2026-08-12 06:19:10 on dist-test-slave-04bb"
I20260812 06:19:10.671099 21281 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-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:10.679543 21281 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:10.679961 21281 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:10.680446 21281 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:10.681289 21281 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:10.681363 21281 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:10.681471 21281 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:10.681519 21281 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:10.688259 21281 rpc_server.cc:307] RPC server started. Bound to: 127.20.200.65:46041
I20260812 06:19:10.688453 21521 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.200.65:46041 every 8 connection(s)
I20260812 06:19:10.702569 21522 heartbeater.cc:344] Connected to a master server at 127.20.200.126:42177
I20260812 06:19:10.702862 21522 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:10.703365 21522 heartbeater.cc:507] Master 127.20.200.126:42177 requested a full tablet report, sending...
I20260812 06:19:10.704875 21334 ts_manager.cc:194] Registered new tserver with Master: e6912182d6864ffe9b15edaa54ea7a50 (127.20.200.65:46041)
I20260812 06:19:10.705757 21281 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016778571s
I20260812 06:19:10.706223 21334 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55810
I20260812 06:19:10.714951 21334 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55812:
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:10.730046 21474 tablet_service.cc:1511] Processing CreateTablet for tablet 8d0e1da788054191b53e3637c6a83cb3 (DEFAULT_TABLE table=heavy-update-compaction-test [id=76fd7472e8684fa19f522c92f5ceef1c]), partition=
I20260812 06:19:10.730595 21474 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8d0e1da788054191b53e3637c6a83cb3. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:10.733500 21541 tablet_bootstrap.cc:492] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Bootstrap starting.
I20260812 06:19:10.734364 21541 tablet_bootstrap.cc:654] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:10.735466 21541 tablet_bootstrap.cc:492] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: No bootstrap required, opened a new log
I20260812 06:19:10.735589 21541 ts_tablet_manager.cc:1403] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:10.736219 21541 raft_consensus.cc:359] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e6912182d6864ffe9b15edaa54ea7a50" member_type: VOTER last_known_addr { host: "127.20.200.65" port: 46041 } }
I20260812 06:19:10.736423 21541 raft_consensus.cc:385] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:10.736493 21541 raft_consensus.cc:740] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e6912182d6864ffe9b15edaa54ea7a50, State: Initialized, Role: FOLLOWER
I20260812 06:19:10.736693 21541 consensus_queue.cc:260] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50 [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: "e6912182d6864ffe9b15edaa54ea7a50" member_type: VOTER last_known_addr { host: "127.20.200.65" port: 46041 } }
I20260812 06:19:10.736814 21541 raft_consensus.cc:399] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:10.736869 21541 raft_consensus.cc:493] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:10.736931 21541 raft_consensus.cc:3060] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:10.737699 21541 raft_consensus.cc:515] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e6912182d6864ffe9b15edaa54ea7a50" member_type: VOTER last_known_addr { host: "127.20.200.65" port: 46041 } }
I20260812 06:19:10.737854 21541 leader_election.cc:304] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50 [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: e6912182d6864ffe9b15edaa54ea7a50; no voters: 
I20260812 06:19:10.738085 21541 leader_election.cc:290] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:10.738188 21543 raft_consensus.cc:2804] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:10.738385 21543 raft_consensus.cc:697] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50 [term 1 LEADER]: Becoming Leader. State: Replica: e6912182d6864ffe9b15edaa54ea7a50, State: Running, Role: LEADER
I20260812 06:19:10.738454 21541 ts_tablet_manager.cc:1434] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:10.738706 21522 heartbeater.cc:499] Master 127.20.200.126:42177 was elected leader, sending a full tablet report...
I20260812 06:19:10.738988 21543 consensus_queue.cc:237] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50 [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: "e6912182d6864ffe9b15edaa54ea7a50" member_type: VOTER last_known_addr { host: "127.20.200.65" port: 46041 } }
I20260812 06:19:10.741819 21334 catalog_manager.cc:5719] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50 reported cstate change: term changed from 0 to 1, leader changed from <none> to e6912182d6864ffe9b15edaa54ea7a50 (127.20.200.65). New cstate: current_term: 1 leader_uuid: "e6912182d6864ffe9b15edaa54ea7a50" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e6912182d6864ffe9b15edaa54ea7a50" member_type: VOTER last_known_addr { host: "127.20.200.65" port: 46041 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:10.806231 21281 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.017s	sys 0.008s
I20260812 06:19:10.939407 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushMRSOp(8d0e1da788054191b53e3637c6a83cb3): perf score=19.054940
I20260812 06:19:11.138023 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushMRSOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.198s	user 0.153s	sys 0.036s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":64617,"compiler_manager_pool.run_cpu_time_us":195716,"compiler_manager_pool.run_wall_time_us":195812,"delete_count":0,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":187,"dirs.run_wall_time_us":1090,"drs_written":1,"lbm_read_time_us":101,"lbm_reads_lt_1ms":4,"lbm_write_time_us":49146,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":149,"threads_started":1,"update_count":1500}
I20260812 06:19:11.139225 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling LogGCOp(8d0e1da788054191b53e3637c6a83cb3): free 20743880 bytes of WAL
I20260812 06:19:11.139536 21435 log_reader.cc:385] T 8d0e1da788054191b53e3637c6a83cb3: removed 2 log segments from log reader
I20260812 06:19:11.139621 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000001 (ops 1-6)
I20260812 06:19:11.139706 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000002 (ops 7-11)
I20260812 06:19:11.144160 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: LogGCOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:11.144601 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:11.162153 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.017s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4886,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.162775 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling UndoDeltaBlockGCOp(8d0e1da788054191b53e3637c6a83cb3): 16411392 bytes on disk
I20260812 06:19:11.163374 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: UndoDeltaBlockGCOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:19:11.163825 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:11.319569 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.156s	user 0.099s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":874,"lbm_read_time_us":10201,"lbm_reads_lt_1ms":460,"lbm_write_time_us":26042,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":322,"threads_started":5,"update_count":2000}
I20260812 06:19:11.320147 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=11.118625
I20260812 06:19:11.371272 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.051s	user 0.028s	sys 0.017s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":21689,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:11.371996 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:11.389521 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6956,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.389940 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:11.399708 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4040,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:11.400161 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:11.563664 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.163s	user 0.138s	sys 0.016s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":934,"lbm_read_time_us":12468,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29579,"lbm_writes_lt_1ms":543,"mutex_wait_us":393,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:11.564366 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=14.095187
I20260812 06:19:11.617141 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.053s	user 0.025s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23444,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:11.617637 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:11.633436 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.016s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6202,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.634115 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:11.793020 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.159s	user 0.112s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1011,"lbm_read_time_us":12489,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29567,"lbm_writes_lt_1ms":543,"mutex_wait_us":92,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":51072,"update_count":2500}
I20260812 06:19:11.793632 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=13.103000
I20260812 06:19:11.843005 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.049s	user 0.030s	sys 0.016s Metrics: {"bytes_written":15097133,"delete_count":0,"lbm_write_time_us":22190,"lbm_writes_lt_1ms":371,"reinsert_count":0,"update_count":1840}
I20260812 06:19:11.843470 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:11.858976 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.015s	user 0.000s	sys 0.004s Metrics: {"bytes_written":1723206,"delete_count":0,"lbm_write_time_us":1914,"lbm_writes_lt_1ms":45,"reinsert_count":0,"update_count":210}
I20260812 06:19:11.859414 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:11.868925 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3603,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:11.869344 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:12.046676 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.177s	user 0.103s	sys 0.063s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774745,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":433,"lbm_read_time_us":12951,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28221,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:19:12.047314 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=14.095187
I20260812 06:19:12.107945 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.060s	user 0.022s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20572,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:12.108454 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:12.119004 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4317,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.119414 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:12.305188 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.186s	user 0.135s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":330,"lbm_read_time_us":12245,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32012,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":91904,"update_count":2500}
I20260812 06:19:12.305924 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=14.095187
I20260812 06:19:12.372314 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.066s	user 0.026s	sys 0.028s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":20797,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:12.372951 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:12.390596 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6560,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.391311 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushMRSOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:12.431066 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushMRSOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.040s	user 0.031s	sys 0.003s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1437,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1598,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:12.431866 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling LogGCOp(8d0e1da788054191b53e3637c6a83cb3): free 112239263 bytes of WAL
I20260812 06:19:12.432101 21435 log_reader.cc:385] T 8d0e1da788054191b53e3637c6a83cb3: removed 11 log segments from log reader
I20260812 06:19:12.432149 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000003 (ops 12-16)
I20260812 06:19:12.432179 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000004 (ops 17-20)
I20260812 06:19:12.432250 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000005 (ops 21-25)
I20260812 06:19:12.432293 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000006 (ops 26-30)
I20260812 06:19:12.432340 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000007 (ops 31-35)
I20260812 06:19:12.432384 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000008 (ops 36-40)
I20260812 06:19:12.432423 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000009 (ops 41-45)
I20260812 06:19:12.432485 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000010 (ops 46-50)
I20260812 06:19:12.432554 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000011 (ops 51-55)
I20260812 06:19:12.432595 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000012 (ops 56-60)
I20260812 06:19:12.432636 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000013 (ops 61-65)
I20260812 06:19:12.459827 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: LogGCOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:12.460283 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling UndoDeltaBlockGCOp(8d0e1da788054191b53e3637c6a83cb3): 463 bytes on disk
I20260812 06:19:12.460834 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: UndoDeltaBlockGCOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:19:12.461357 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:12.483469 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.022s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5923,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.483940 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:12.494498 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4043,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.494975 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:12.731135 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.236s	user 0.166s	sys 0.060s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979748,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":151,"lbm_read_time_us":15411,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41950,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:19:12.731647 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=18.063937
I20260812 06:19:12.798303 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.066s	user 0.049s	sys 0.011s Metrics: {"bytes_written":20512312,"delete_count":0,"lbm_write_time_us":28506,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:12.798821 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:12.810804 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4350,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.811259 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:12.971457 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.160s	user 0.140s	sys 0.020s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":328,"lbm_read_time_us":13180,"lbm_reads_lt_1ms":672,"lbm_write_time_us":30711,"lbm_writes_lt_1ms":643,"mutex_wait_us":114,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:19:12.972075 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=14.095187
I20260812 06:19:13.023500 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.051s	user 0.029s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22021,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.024245 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:13.052330 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.028s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5795,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.052877 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:13.063855 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4113,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.064442 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:13.239521 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.175s	user 0.133s	sys 0.040s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877217,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":631,"lbm_read_time_us":14348,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36686,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":3000}
I20260812 06:19:13.240121 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=14.095187
I20260812 06:19:13.293555 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.053s	user 0.037s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20556,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.294019 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:13.306555 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4422,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.307209 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:13.471210 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.164s	user 0.124s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":420,"lbm_read_time_us":10816,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29947,"lbm_writes_lt_1ms":543,"mutex_wait_us":87,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:13.471909 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=14.095187
I20260812 06:19:13.539530 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.067s	user 0.020s	sys 0.020s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":44146,"lbm_writes_1-10_ms":1,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.540017 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:13.560084 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.020s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5884,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.560637 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:13.753852 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.193s	user 0.128s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1303,"lbm_read_time_us":11304,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34110,"lbm_writes_lt_1ms":543,"mutex_wait_us":195,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:13.754356 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=14.095187
I20260812 06:19:13.809554 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.055s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24990,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.810066 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushMRSOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:13.834216 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushMRSOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.024s	user 0.022s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":1371,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1436,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:13.834901 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling LogGCOp(8d0e1da788054191b53e3637c6a83cb3): free 120553382 bytes of WAL
I20260812 06:19:13.835135 21435 log_reader.cc:385] T 8d0e1da788054191b53e3637c6a83cb3: removed 12 log segments from log reader
I20260812 06:19:13.835181 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000014 (ops 66-70)
I20260812 06:19:13.835210 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000015 (ops 71-74)
I20260812 06:19:13.835263 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000016 (ops 75-79)
I20260812 06:19:13.835309 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000017 (ops 80-84)
I20260812 06:19:13.835372 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000018 (ops 85-89)
I20260812 06:19:13.835418 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000019 (ops 90-94)
I20260812 06:19:13.835474 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000020 (ops 95-98)
I20260812 06:19:13.835503 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000021 (ops 99-103)
I20260812 06:19:13.835538 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000022 (ops 104-108)
I20260812 06:19:13.835577 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000023 (ops 109-113)
I20260812 06:19:13.835605 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000024 (ops 114-118)
I20260812 06:19:13.835639 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000025 (ops 119-123)
I20260812 06:19:13.864195 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: LogGCOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:13.864826 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling UndoDeltaBlockGCOp(8d0e1da788054191b53e3637c6a83cb3): 462 bytes on disk
I20260812 06:19:13.865252 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: UndoDeltaBlockGCOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:19:13.865762 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=5.165500
I20260812 06:19:13.886529 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.021s	user 0.010s	sys 0.009s Metrics: {"bytes_written":6769231,"delete_count":0,"lbm_write_time_us":8815,"lbm_writes_lt_1ms":168,"reinsert_count":0,"update_count":825}
I20260812 06:19:13.886960 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:13.892926 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.006s	user 0.002s	sys 0.004s Metrics: {"bytes_written":1436027,"delete_count":0,"lbm_write_time_us":1558,"lbm_writes_lt_1ms":38,"reinsert_count":0,"update_count":175}
I20260812 06:19:13.893369 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:14.109920 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.216s	user 0.129s	sys 0.069s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877155,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":559,"lbm_read_time_us":14862,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34728,"lbm_writes_lt_1ms":643,"mutex_wait_us":38,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13440,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:19:14.110680 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=18.063937
I20260812 06:19:14.179844 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.069s	user 0.050s	sys 0.012s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":29712,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:14.180303 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:14.190552 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4049,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.191047 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:14.384436 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.193s	user 0.139s	sys 0.051s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":204,"lbm_read_time_us":15161,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32149,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":23168,"update_count":3000}
I20260812 06:19:14.385002 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=14.095187
I20260812 06:19:14.440809 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.056s	user 0.042s	sys 0.012s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24435,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.441303 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:14.454211 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4451,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.454802 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:14.630671 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.176s	user 0.131s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1310,"lbm_read_time_us":10915,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32122,"lbm_writes_lt_1ms":543,"mutex_wait_us":603,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:19:14.631256 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=14.095187
I20260812 06:19:14.707989 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.077s	user 0.019s	sys 0.039s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28198,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.708468 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:14.719419 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4272,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.720424 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:14.895479 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.175s	user 0.100s	sys 0.072s 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":845,"lbm_read_time_us":12582,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31718,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:19:14.896039 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=14.095187
I20260812 06:19:14.964000 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.068s	user 0.017s	sys 0.047s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24409,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.964758 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:14.976024 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4521,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.976490 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:15.164652 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.188s	user 0.129s	sys 0.049s 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":426,"lbm_read_time_us":14203,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31942,"lbm_writes_lt_1ms":543,"mutex_wait_us":88,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:19:15.165215 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=14.095187
I20260812 06:19:15.232472 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.067s	user 0.029s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20925,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.233219 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:15.245381 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4738,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.246137 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:15.455484 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.209s	user 0.131s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":727,"lbm_read_time_us":13988,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35348,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:19:15.456184 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=14.095187
I20260812 06:19:15.513622 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.057s	user 0.033s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27052,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.514253 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:15.539826 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.025s	user 0.001s	sys 0.021s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6429,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.540665 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushMRSOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:15.571259 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushMRSOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.030s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":96,"dirs.run_cpu_time_us":258,"dirs.run_wall_time_us":1616,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1658,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:15.572150 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling LogGCOp(8d0e1da788054191b53e3637c6a83cb3): free 140885708 bytes of WAL
I20260812 06:19:15.572432 21435 log_reader.cc:385] T 8d0e1da788054191b53e3637c6a83cb3: removed 14 log segments from log reader
I20260812 06:19:15.572499 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000026 (ops 124-128)
I20260812 06:19:15.572573 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000027 (ops 129-132)
I20260812 06:19:15.572602 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000028 (ops 133-137)
I20260812 06:19:15.572624 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000029 (ops 138-142)
I20260812 06:19:15.572654 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000030 (ops 143-147)
I20260812 06:19:15.572683 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000031 (ops 148-152)
I20260812 06:19:15.572714 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000032 (ops 153-157)
I20260812 06:19:15.572736 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000033 (ops 158-162)
I20260812 06:19:15.572765 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000034 (ops 163-166)
I20260812 06:19:15.572801 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000035 (ops 167-171)
I20260812 06:19:15.572836 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000036 (ops 172-176)
I20260812 06:19:15.572866 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000037 (ops 177-181)
I20260812 06:19:15.572894 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000038 (ops 182-186)
I20260812 06:19:15.572916 21435 log.cc:1079] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/8d0e1da788054191b53e3637c6a83cb3/wal-000000039 (ops 187-190)
I20260812 06:19:15.609189 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: LogGCOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.037s	user 0.001s	sys 0.035s Metrics: {}
I20260812 06:19:15.609771 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:15.631624 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.022s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4749,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.632124 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=2.188937
I20260812 06:19:15.642784 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4047,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.643275 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling UndoDeltaBlockGCOp(8d0e1da788054191b53e3637c6a83cb3): 493 bytes on disk
I20260812 06:19:15.643785 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: UndoDeltaBlockGCOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:19:15.644428 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:15.829226 21281 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.023s	user 1.907s	sys 0.132s
I20260812 06:19:15.862584 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.217s	user 0.159s	sys 0.056s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":15384,"lbm_reads_lt_1ms":770,"lbm_write_time_us":37688,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":3500}
I20260812 06:19:15.863139 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3): perf score=14.095187
I20260812 06:19:15.898339 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: FlushDeltaMemStoresOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.035s	user 0.023s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17422,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.898869 21523 maintenance_manager.cc:419] P e6912182d6864ffe9b15edaa54ea7a50: Scheduling MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3): perf score=1.000000
I20260812 06:19:15.952348 21281 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.122s	user 0.002s	sys 0.000s
I20260812 06:19:15.953173 21281 tablet_server.cc:179] TabletServer@127.20.200.65:0 shutting down...
I20260812 06:19:16.023891 21435 maintenance_manager.cc:643] P e6912182d6864ffe9b15edaa54ea7a50: MajorDeltaCompactionOp(8d0e1da788054191b53e3637c6a83cb3) complete. Timing: real 0.125s	user 0.088s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":455,"lbm_read_time_us":10708,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25269,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":101,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.024768 21281 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:16.025244 21281 tablet_replica.cc:333] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50: stopping tablet replica
I20260812 06:19:16.025502 21281 raft_consensus.cc:2243] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:16.025744 21281 raft_consensus.cc:2272] T 8d0e1da788054191b53e3637c6a83cb3 P e6912182d6864ffe9b15edaa54ea7a50 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:16.041985 21281 tablet_server.cc:196] TabletServer@127.20.200.65:0 shutdown complete.
I20260812 06:19:16.064854 21281 master.cc:562] Master@127.20.200.126:42177 shutting down...
I20260812 06:19:16.068943 21281 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:16.069190 21281 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:16.069308 21281 tablet_replica.cc:333] T 00000000000000000000000000000000 P e5cc25b0d8394166a700c606697e4c04: stopping tablet replica
I20260812 06:19:16.081975 21281 master.cc:584] Master@127.20.200.126:42177 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5654 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:16.177584 21281 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.200.126:43331
I20260812 06:19:16.178011 21281 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:16.180033 21572 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:16.180160 21281 server_base.cc:1061] running on GCE node
W20260812 06:19:16.180361 21571 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:16.180351 21574 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:16.180716 21281 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:16.180770 21281 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:16.180786 21281 hybrid_clock.cc:648] HybridClock initialized: now 1786515556180786 us; error 0 us; skew 500 ppm
I20260812 06:19:16.181674 21281 webserver.cc:533] Webserver started at http://127.20.200.126:40259/ using document root <none> and password file <none>
I20260812 06:19:16.181859 21281 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:16.181908 21281 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:16.182024 21281 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:16.182458 21281 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/master-0-root/instance:
uuid: "0d6c212c223a4839878fef9cff0e9b27"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-04bb"
I20260812 06:19:16.183965 21281 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:16.184973 21582 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:16.185242 21281 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:16.185310 21281 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/master-0-root
uuid: "0d6c212c223a4839878fef9cff0e9b27"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-04bb"
I20260812 06:19:16.185405 21281 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-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:16.206108 21281 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:16.206584 21281 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:16.211088 21281 rpc_server.cc:307] RPC server started. Bound to: 127.20.200.126:43331
I20260812 06:19:16.221771 21663 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.200.126:43331 every 8 connection(s)
I20260812 06:19:16.230026 21664 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:16.232229 21664 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27: Bootstrap starting.
I20260812 06:19:16.233127 21664 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:16.234256 21664 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27: No bootstrap required, opened a new log
I20260812 06:19:16.234690 21664 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0d6c212c223a4839878fef9cff0e9b27" member_type: VOTER }
I20260812 06:19:16.234782 21664 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:16.234807 21664 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0d6c212c223a4839878fef9cff0e9b27, State: Initialized, Role: FOLLOWER
I20260812 06:19:16.235008 21664 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [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: "0d6c212c223a4839878fef9cff0e9b27" member_type: VOTER }
I20260812 06:19:16.235085 21664 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:16.235107 21664 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:16.235181 21664 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:16.235918 21664 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0d6c212c223a4839878fef9cff0e9b27" member_type: VOTER }
I20260812 06:19:16.236069 21664 leader_election.cc:304] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [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: 0d6c212c223a4839878fef9cff0e9b27; no voters: 
I20260812 06:19:16.236294 21664 leader_election.cc:290] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:16.236478 21667 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:16.236745 21667 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [term 1 LEADER]: Becoming Leader. State: Replica: 0d6c212c223a4839878fef9cff0e9b27, State: Running, Role: LEADER
I20260812 06:19:16.236851 21664 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:16.236913 21667 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [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: "0d6c212c223a4839878fef9cff0e9b27" member_type: VOTER }
I20260812 06:19:16.237392 21670 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0d6c212c223a4839878fef9cff0e9b27. Latest consensus state: current_term: 1 leader_uuid: "0d6c212c223a4839878fef9cff0e9b27" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0d6c212c223a4839878fef9cff0e9b27" member_type: VOTER } }
I20260812 06:19:16.237493 21670 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:16.237376 21669 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0d6c212c223a4839878fef9cff0e9b27" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0d6c212c223a4839878fef9cff0e9b27" member_type: VOTER } }
I20260812 06:19:16.237546 21669 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:16.237808 21675 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:16.238586 21675 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:16.238915 21281 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:16.240439 21675 catalog_manager.cc:1383] Generated new cluster ID: f17dccefcd574167b448a80f55e29026
I20260812 06:19:16.240502 21675 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:16.264099 21675 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:16.264768 21675 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:16.275233 21675 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27: Generated new TSK 0
I20260812 06:19:16.275425 21675 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:16.303711 21281 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:16.305950 21703 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:16.305964 21707 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:16.306059 21281 server_base.cc:1061] running on GCE node
W20260812 06:19:16.305956 21702 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:16.306464 21281 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:16.306514 21281 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:16.306530 21281 hybrid_clock.cc:648] HybridClock initialized: now 1786515556306531 us; error 0 us; skew 500 ppm
I20260812 06:19:16.307404 21281 webserver.cc:533] Webserver started at http://127.20.200.65:46775/ using document root <none> and password file <none>
I20260812 06:19:16.307583 21281 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:16.307653 21281 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:16.307746 21281 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:16.308173 21281 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/instance:
uuid: "5203dcfc99164bfaadeeecdf4072983a"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-04bb"
I20260812 06:19:16.309770 21281 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:16.310716 21714 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:16.310989 21281 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:16.311122 21281 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root
uuid: "5203dcfc99164bfaadeeecdf4072983a"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-04bb"
I20260812 06:19:16.311204 21281 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-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:16.325749 21281 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:16.326213 21281 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:16.326546 21281 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:16.327042 21281 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:16.327103 21281 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:16.327165 21281 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:16.327211 21281 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:16.331650 21281 rpc_server.cc:307] RPC server started. Bound to: 127.20.200.65:41967
I20260812 06:19:16.331693 21807 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.200.65:41967 every 8 connection(s)
I20260812 06:19:16.352399 21808 heartbeater.cc:344] Connected to a master server at 127.20.200.126:43331
I20260812 06:19:16.352583 21808 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:16.352833 21808 heartbeater.cc:507] Master 127.20.200.126:43331 requested a full tablet report, sending...
I20260812 06:19:16.353498 21607 ts_manager.cc:194] Registered new tserver with Master: 5203dcfc99164bfaadeeecdf4072983a (127.20.200.65:41967)
I20260812 06:19:16.354295 21281 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.022195232s
I20260812 06:19:16.354317 21607 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:38982
I20260812 06:19:16.361941 21607 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:38988:
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:16.370633 21750 tablet_service.cc:1511] Processing CreateTablet for tablet 1ca1bf48a9664f3fa8d9de2877194e5e (DEFAULT_TABLE table=heavy-update-compaction-test [id=cd794859a1754ae490fdf290e2ebc539]), partition=
I20260812 06:19:16.370925 21750 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1ca1bf48a9664f3fa8d9de2877194e5e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:16.373039 21828 tablet_bootstrap.cc:492] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Bootstrap starting.
I20260812 06:19:16.373915 21828 tablet_bootstrap.cc:654] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:16.374970 21828 tablet_bootstrap.cc:492] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: No bootstrap required, opened a new log
I20260812 06:19:16.375042 21828 ts_tablet_manager.cc:1403] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:16.375481 21828 raft_consensus.cc:359] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5203dcfc99164bfaadeeecdf4072983a" member_type: VOTER last_known_addr { host: "127.20.200.65" port: 41967 } }
I20260812 06:19:16.375581 21828 raft_consensus.cc:385] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:16.375641 21828 raft_consensus.cc:740] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5203dcfc99164bfaadeeecdf4072983a, State: Initialized, Role: FOLLOWER
I20260812 06:19:16.375808 21828 consensus_queue.cc:260] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a [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: "5203dcfc99164bfaadeeecdf4072983a" member_type: VOTER last_known_addr { host: "127.20.200.65" port: 41967 } }
I20260812 06:19:16.375895 21828 raft_consensus.cc:399] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:16.375964 21828 raft_consensus.cc:493] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:16.376024 21828 raft_consensus.cc:3060] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:16.376941 21828 raft_consensus.cc:515] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5203dcfc99164bfaadeeecdf4072983a" member_type: VOTER last_known_addr { host: "127.20.200.65" port: 41967 } }
I20260812 06:19:16.377058 21828 leader_election.cc:304] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a [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: 5203dcfc99164bfaadeeecdf4072983a; no voters: 
I20260812 06:19:16.377208 21828 leader_election.cc:290] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:16.377348 21833 raft_consensus.cc:2804] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:16.377516 21808 heartbeater.cc:499] Master 127.20.200.126:43331 was elected leader, sending a full tablet report...
I20260812 06:19:16.377553 21833 raft_consensus.cc:697] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a [term 1 LEADER]: Becoming Leader. State: Replica: 5203dcfc99164bfaadeeecdf4072983a, State: Running, Role: LEADER
I20260812 06:19:16.377725 21833 consensus_queue.cc:237] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a [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: "5203dcfc99164bfaadeeecdf4072983a" member_type: VOTER last_known_addr { host: "127.20.200.65" port: 41967 } }
I20260812 06:19:16.377806 21828 ts_tablet_manager.cc:1434] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:16.379014 21607 catalog_manager.cc:5719] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a reported cstate change: term changed from 0 to 1, leader changed from <none> to 5203dcfc99164bfaadeeecdf4072983a (127.20.200.65). New cstate: current_term: 1 leader_uuid: "5203dcfc99164bfaadeeecdf4072983a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5203dcfc99164bfaadeeecdf4072983a" member_type: VOTER last_known_addr { host: "127.20.200.65" port: 41967 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:16.441380 21281 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.015s	sys 0.008s
I20260812 06:19:16.582527 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushMRSOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=19.054940
I20260812 06:19:16.745265 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushMRSOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.163s	user 0.114s	sys 0.044s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1017,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44033,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:16.745829 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling LogGCOp(1ca1bf48a9664f3fa8d9de2877194e5e): free 20743880 bytes of WAL
I20260812 06:19:16.746047 21720 log_reader.cc:385] T 1ca1bf48a9664f3fa8d9de2877194e5e: removed 2 log segments from log reader
I20260812 06:19:16.746094 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000001 (ops 1-6)
I20260812 06:19:16.746124 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000002 (ops 7-11)
I20260812 06:19:16.750578 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: LogGCOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:16.750898 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling UndoDeltaBlockGCOp(1ca1bf48a9664f3fa8d9de2877194e5e): 16411392 bytes on disk
I20260812 06:19:16.751276 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: UndoDeltaBlockGCOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:16.751644 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:16.769459 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.018s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6125,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.769990 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:16.925666 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.155s	user 0.117s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":549,"lbm_read_time_us":11518,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25738,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":386,"threads_started":5,"update_count":2000}
I20260812 06:19:16.926460 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=11.118625
I20260812 06:19:16.966536 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.040s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":18341,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:16.967046 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:16.977900 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3774,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:16.978379 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:17.115216 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.137s	user 0.113s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":281,"lbm_read_time_us":11131,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27059,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2000}
I20260812 06:19:17.115727 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=10.126437
I20260812 06:19:17.155741 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.040s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17838,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.156266 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:17.167255 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4196,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.168578 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:17.300015 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.131s	user 0.102s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":899,"lbm_read_time_us":11500,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25107,"lbm_writes_lt_1ms":443,"mutex_wait_us":127,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2000}
I20260812 06:19:17.300513 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=10.126437
I20260812 06:19:17.352855 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.052s	user 0.016s	sys 0.036s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20084,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.353432 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:17.364339 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4185,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.364861 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:17.534279 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.169s	user 0.125s	sys 0.044s 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":431,"lbm_read_time_us":12985,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27070,"lbm_writes_lt_1ms":443,"mutex_wait_us":98,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2000}
I20260812 06:19:17.537585 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=10.126437
I20260812 06:19:17.574798 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.037s	user 0.014s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14480,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.575273 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:17.586292 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4077,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.587112 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:17.721024 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.134s	user 0.114s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":759,"lbm_read_time_us":10293,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25187,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:19:17.721606 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=10.126437
I20260812 06:19:17.766683 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.045s	user 0.010s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15959,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.767170 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:17.778214 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4129,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.778824 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:17.902508 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.124s	user 0.096s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":236,"lbm_read_time_us":8160,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25525,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17024,"update_count":2000}
I20260812 06:19:17.903054 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=10.126437
I20260812 06:19:17.954922 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.052s	user 0.031s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15731,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.955471 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:17.966269 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4288,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.966715 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushMRSOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:17.996412 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushMRSOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.030s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":1331,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1439,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:17.997095 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:18.172174 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.175s	user 0.124s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":274,"lbm_read_time_us":11634,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27834,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2000}
I20260812 06:19:18.172788 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling LogGCOp(1ca1bf48a9664f3fa8d9de2877194e5e): free 112239310 bytes of WAL
I20260812 06:19:18.173022 21720 log_reader.cc:385] T 1ca1bf48a9664f3fa8d9de2877194e5e: removed 11 log segments from log reader
I20260812 06:19:18.173082 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000003 (ops 12-16)
I20260812 06:19:18.173170 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000004 (ops 17-21)
I20260812 06:19:18.173211 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000005 (ops 22-26)
I20260812 06:19:18.173280 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000006 (ops 27-31)
I20260812 06:19:18.173319 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000007 (ops 32-36)
I20260812 06:19:18.173388 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000008 (ops 37-40)
I20260812 06:19:18.173434 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000009 (ops 41-45)
I20260812 06:19:18.173472 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000010 (ops 46-50)
I20260812 06:19:18.173511 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000011 (ops 51-55)
I20260812 06:19:18.173555 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000012 (ops 56-60)
I20260812 06:19:18.173628 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000013 (ops 61-65)
I20260812 06:19:18.198668 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: LogGCOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.026s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:18.199136 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=14.095187
I20260812 06:19:18.245587 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.046s	user 0.026s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20631,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.246215 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:18.283546 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.037s	user 0.001s	sys 0.023s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6284,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.284267 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling UndoDeltaBlockGCOp(1ca1bf48a9664f3fa8d9de2877194e5e): 447 bytes on disk
I20260812 06:19:18.284863 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: UndoDeltaBlockGCOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4}
I20260812 06:19:18.285478 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:18.304191 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.019s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7150,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.304804 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:18.520180 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.215s	user 0.137s	sys 0.076s 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":1009,"lbm_read_time_us":16113,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38075,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":434,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":3000}
I20260812 06:19:18.520888 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=14.095187
I20260812 06:19:18.582752 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.062s	user 0.029s	sys 0.030s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22591,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.583330 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:18.594079 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4268,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.594504 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:18.781548 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.187s	user 0.136s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":224,"lbm_read_time_us":12838,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31271,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:18.782230 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=14.095187
I20260812 06:19:18.833062 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.051s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19715,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.833590 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:18.855082 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.021s	user 0.009s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4389,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.855695 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:19.047552 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.192s	user 0.098s	sys 0.089s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":188,"lbm_read_time_us":13334,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31586,"lbm_writes_lt_1ms":543,"mutex_wait_us":85,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:19:19.048276 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=14.095187
I20260812 06:19:19.102142 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.054s	user 0.025s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20385,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.102661 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:19.114285 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4163,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.114742 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:19.290823 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.176s	user 0.107s	sys 0.064s 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":265,"lbm_read_time_us":9471,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29258,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2500}
I20260812 06:19:19.291527 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=14.095187
I20260812 06:19:19.347368 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.056s	user 0.029s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25407,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.347927 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:19.360594 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.012s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4986,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.361119 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:19.545380 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.184s	user 0.148s	sys 0.027s 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":100,"lbm_read_time_us":11432,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36421,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:19:19.546151 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=14.095187
I20260812 06:19:19.593904 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.048s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20625,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.594596 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:19.605042 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3996,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.605518 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushMRSOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:19.641000 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushMRSOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.035s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1516,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2035,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:19.641688 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling LogGCOp(1ca1bf48a9664f3fa8d9de2877194e5e): free 128414394 bytes of WAL
I20260812 06:19:19.641924 21720 log_reader.cc:385] T 1ca1bf48a9664f3fa8d9de2877194e5e: removed 13 log segments from log reader
I20260812 06:19:19.641973 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000014 (ops 66-70)
I20260812 06:19:19.642001 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000015 (ops 71-75)
I20260812 06:19:19.642066 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000016 (ops 76-80)
I20260812 06:19:19.642095 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000017 (ops 81-84)
I20260812 06:19:19.642136 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000018 (ops 85-89)
I20260812 06:19:19.642192 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000019 (ops 90-94)
I20260812 06:19:19.642231 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000020 (ops 95-98)
I20260812 06:19:19.642269 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000021 (ops 99-103)
I20260812 06:19:19.642318 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000022 (ops 104-108)
I20260812 06:19:19.642354 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000023 (ops 109-112)
I20260812 06:19:19.642391 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000024 (ops 113-117)
I20260812 06:19:19.642429 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000025 (ops 118-122)
I20260812 06:19:19.642467 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000026 (ops 123-126)
I20260812 06:19:19.672406 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: LogGCOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.031s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:19.673014 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=4.173312
I20260812 06:19:19.686982 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":5579536,"delete_count":0,"lbm_write_time_us":5686,"lbm_writes_lt_1ms":139,"reinsert_count":0,"update_count":680}
I20260812 06:19:19.687453 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling UndoDeltaBlockGCOp(1ca1bf48a9664f3fa8d9de2877194e5e): 483 bytes on disk
I20260812 06:19:19.687870 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: UndoDeltaBlockGCOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:19.688364 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.196750
I20260812 06:19:19.706439 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.018s	user 0.009s	sys 0.007s Metrics: {"bytes_written":2625754,"delete_count":0,"lbm_write_time_us":3096,"lbm_writes_lt_1ms":67,"reinsert_count":0,"update_count":320}
I20260812 06:19:19.706943 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:19.941411 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.234s	user 0.138s	sys 0.095s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979715,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":764,"lbm_read_time_us":16960,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39468,"lbm_writes_lt_1ms":743,"mutex_wait_us":296,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:19:19.943053 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=18.063937
I20260812 06:19:20.004201 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.061s	user 0.041s	sys 0.016s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27962,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:20.004947 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:20.023335 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.018s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4584,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.023895 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:20.245808 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.222s	user 0.145s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":703,"lbm_read_time_us":13770,"lbm_reads_lt_1ms":664,"lbm_write_time_us":37509,"lbm_writes_lt_1ms":643,"mutex_wait_us":57,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":3000}
I20260812 06:19:20.246348 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=18.063937
I20260812 06:19:20.317168 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.071s	user 0.024s	sys 0.038s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":27996,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:20.317691 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:20.329033 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4223,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.329763 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:20.539613 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.210s	user 0.137s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1111,"lbm_read_time_us":14685,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36306,"lbm_writes_lt_1ms":643,"mutex_wait_us":264,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":3000}
I20260812 06:19:20.541666 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=15.087375
I20260812 06:19:20.591133 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.049s	user 0.022s	sys 0.024s Metrics: {"bytes_written":16697070,"delete_count":0,"lbm_write_time_us":22545,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":409,"reinsert_count":0,"update_count":2035}
I20260812 06:19:20.591647 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:20.615140 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.023s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":4373,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:19:20.615657 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:20.626840 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4394,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.627317 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:20.846318 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.219s	user 0.121s	sys 0.094s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877213,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":212,"lbm_read_time_us":14890,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37456,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":3000}
I20260812 06:19:20.847788 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=17.071750
I20260812 06:19:20.904300 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.056s	user 0.040s	sys 0.008s Metrics: {"bytes_written":18707251,"delete_count":0,"lbm_write_time_us":24111,"lbm_writes_lt_1ms":459,"reinsert_count":0,"update_count":2280}
I20260812 06:19:20.904920 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.196750
I20260812 06:19:20.914053 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.009s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2338587,"delete_count":0,"lbm_write_time_us":2549,"lbm_writes_lt_1ms":60,"reinsert_count":0,"update_count":285}
I20260812 06:19:20.914554 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=2.188937
I20260812 06:19:20.924317 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3569330,"delete_count":0,"lbm_write_time_us":3750,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:19:20.924775 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:21.141438 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.216s	user 0.157s	sys 0.056s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877168,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":160,"lbm_read_time_us":14913,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37495,"lbm_writes_lt_1ms":643,"mutex_wait_us":52,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":3000}
I20260812 06:19:21.142395 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=16.079562
I20260812 06:19:21.214599 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.072s	user 0.047s	sys 0.008s Metrics: {"bytes_written":17845750,"delete_count":0,"lbm_write_time_us":25560,"lbm_writes_lt_1ms":438,"reinsert_count":0,"update_count":2175}
I20260812 06:19:21.215096 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=5.165500
I20260812 06:19:21.233816 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.019s	user 0.009s	sys 0.008s Metrics: {"bytes_written":6769237,"delete_count":0,"lbm_write_time_us":7846,"lbm_writes_lt_1ms":168,"reinsert_count":0,"update_count":825}
I20260812 06:19:21.234333 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushMRSOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:21.267335 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushMRSOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":268,"dirs.run_wall_time_us":1276,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1675,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:21.268169 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling LogGCOp(1ca1bf48a9664f3fa8d9de2877194e5e): free 129773857 bytes of WAL
I20260812 06:19:21.268559 21720 log_reader.cc:385] T 1ca1bf48a9664f3fa8d9de2877194e5e: removed 13 log segments from log reader
I20260812 06:19:21.268641 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000027 (ops 127-131)
I20260812 06:19:21.268702 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000028 (ops 132-136)
I20260812 06:19:21.268734 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000029 (ops 137-141)
I20260812 06:19:21.268772 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000030 (ops 142-146)
I20260812 06:19:21.268810 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000031 (ops 147-151)
I20260812 06:19:21.268846 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000032 (ops 152-156)
I20260812 06:19:21.268882 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000033 (ops 157-160)
I20260812 06:19:21.268919 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000034 (ops 161-165)
I20260812 06:19:21.268954 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000035 (ops 166-170)
I20260812 06:19:21.268991 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000036 (ops 171-175)
I20260812 06:19:21.269028 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000037 (ops 176-180)
I20260812 06:19:21.269064 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000038 (ops 181-185)
I20260812 06:19:21.269100 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000039 (ops 186-190)
I20260812 06:19:21.298877 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: LogGCOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.030s	user 0.002s	sys 0.026s Metrics: {}
I20260812 06:19:21.299386 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=6.157687
I20260812 06:19:21.328274 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: FlushDeltaMemStoresOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.029s	user 0.011s	sys 0.015s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":12815,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:21.328763 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling LogGCOp(1ca1bf48a9664f3fa8d9de2877194e5e): free 11564900 bytes of WAL
I20260812 06:19:21.328974 21720 log_reader.cc:385] T 1ca1bf48a9664f3fa8d9de2877194e5e: removed 1 log segments from log reader
I20260812 06:19:21.329020 21720 log.cc:1079] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: Deleting log segment in path: /tmp/dist-test-taskF3Z0nz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550512063-21281-0/minicluster-data/ts-0-root/wals/1ca1bf48a9664f3fa8d9de2877194e5e/wal-000000040 (ops 191-194)
I20260812 06:19:21.331831 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: LogGCOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:21.332304 21811 maintenance_manager.cc:419] P 5203dcfc99164bfaadeeecdf4072983a: Scheduling MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e): perf score=1.000000
I20260812 06:19:21.452896 21281 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.011s	user 1.840s	sys 0.147s
I20260812 06:19:21.551990 21281 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.099s	user 0.001s	sys 0.000s
I20260812 06:19:21.552495 21281 tablet_server.cc:179] TabletServer@127.20.200.65:0 shutting down...
I20260812 06:19:21.562831 21720 maintenance_manager.cc:643] P 5203dcfc99164bfaadeeecdf4072983a: MajorDeltaCompactionOp(1ca1bf48a9664f3fa8d9de2877194e5e) complete. Timing: real 0.230s	user 0.151s	sys 0.078s Metrics: {"cfile_cache_miss":833,"cfile_cache_miss_bytes":37082054,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":476,"lbm_read_time_us":16916,"lbm_reads_lt_1ms":865,"lbm_write_time_us":40885,"lbm_writes_lt_1ms":843,"mutex_wait_us":85,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":12928,"thread_start_us":80,"threads_started":1,"update_count":4000}
I20260812 06:19:21.563411 21281 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:21.564716 21281 tablet_replica.cc:333] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a: stopping tablet replica
I20260812 06:19:21.564888 21281 raft_consensus.cc:2243] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:21.565059 21281 raft_consensus.cc:2272] T 1ca1bf48a9664f3fa8d9de2877194e5e P 5203dcfc99164bfaadeeecdf4072983a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:21.571941 21281 tablet_server.cc:196] TabletServer@127.20.200.65:0 shutdown complete.
I20260812 06:19:21.634596 21281 master.cc:562] Master@127.20.200.126:43331 shutting down...
I20260812 06:19:21.638398 21281 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:21.638605 21281 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:21.638679 21281 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0d6c212c223a4839878fef9cff0e9b27: stopping tablet replica
I20260812 06:19:21.651264 21281 master.cc:584] Master@127.20.200.126:43331 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5559 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11215 ms total)

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