[==========] 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:20:20.892309 24349 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.23.199.126:40561
I20260812 06:20:20.893530 24349 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:20:20.894227 24349 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:20.901063 24362 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:20.901095 24364 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:20:20.901180 24349 server_base.cc:1061] running on GCE node
W20260812 06:20:20.901381 24370 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:20.901895 24349 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:20.901993 24349 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:20.902021 24349 hybrid_clock.cc:648] HybridClock initialized: now 1786515620902020 us; error 0 us; skew 500 ppm
I20260812 06:20:20.904130 24349 webserver.cc:533] Webserver started at http://127.23.199.126:45689/ using document root <none> and password file <none>
I20260812 06:20:20.904644 24349 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:20.904700 24349 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:20.904975 24349 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:20.906579 24349 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/master-0-root/instance:
uuid: "b5746108ab064e2dbcb62282e8c93886"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-2kcd"
I20260812 06:20:20.910046 24349 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:20.912027 24382 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:20.913125 24349 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:20.913249 24349 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/master-0-root
uuid: "b5746108ab064e2dbcb62282e8c93886"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-2kcd"
I20260812 06:20:20.913347 24349 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:20.928679 24349 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:20.929332 24349 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:20:20.929515 24349 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:20.937278 24349 rpc_server.cc:307] RPC server started. Bound to: 127.23.199.126:40561
I20260812 06:20:20.937291 24477 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.199.126:40561 every 8 connection(s)
I20260812 06:20:20.939515 24478 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:20.945073 24478 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886: Bootstrap starting.
I20260812 06:20:20.947417 24478 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:20.948328 24478 log.cc:826] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:20.950088 24478 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886: No bootstrap required, opened a new log
I20260812 06:20:20.952847 24478 raft_consensus.cc:359] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b5746108ab064e2dbcb62282e8c93886" member_type: VOTER }
I20260812 06:20:20.953043 24478 raft_consensus.cc:385] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:20.953135 24478 raft_consensus.cc:740] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b5746108ab064e2dbcb62282e8c93886, State: Initialized, Role: FOLLOWER
I20260812 06:20:20.953724 24478 consensus_queue.cc:260] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [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: "b5746108ab064e2dbcb62282e8c93886" member_type: VOTER }
I20260812 06:20:20.953898 24478 raft_consensus.cc:399] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:20.953985 24478 raft_consensus.cc:493] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:20.954111 24478 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:20.954890 24478 raft_consensus.cc:515] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b5746108ab064e2dbcb62282e8c93886" member_type: VOTER }
I20260812 06:20:20.955317 24478 leader_election.cc:304] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [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: b5746108ab064e2dbcb62282e8c93886; no voters: 
I20260812 06:20:20.955648 24478 leader_election.cc:290] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:20.955798 24485 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:20.956048 24485 raft_consensus.cc:697] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [term 1 LEADER]: Becoming Leader. State: Replica: b5746108ab064e2dbcb62282e8c93886, State: Running, Role: LEADER
I20260812 06:20:20.956504 24485 consensus_queue.cc:237] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [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: "b5746108ab064e2dbcb62282e8c93886" member_type: VOTER }
I20260812 06:20:20.956636 24478 sys_catalog.cc:565] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:20.958473 24487 sys_catalog.cc:455] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [sys.catalog]: SysCatalogTable state changed. Reason: New leader b5746108ab064e2dbcb62282e8c93886. Latest consensus state: current_term: 1 leader_uuid: "b5746108ab064e2dbcb62282e8c93886" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b5746108ab064e2dbcb62282e8c93886" member_type: VOTER } }
I20260812 06:20:20.958590 24487 sys_catalog.cc:458] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:20.958458 24486 sys_catalog.cc:455] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b5746108ab064e2dbcb62282e8c93886" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b5746108ab064e2dbcb62282e8c93886" member_type: VOTER } }
I20260812 06:20:20.958724 24486 sys_catalog.cc:458] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:20.959002 24349 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:20.960953 24517 catalog_manager.cc:1594] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:20.961033 24517 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:20.961100 24516 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:20.961800 24516 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:20.966491 24516 catalog_manager.cc:1383] Generated new cluster ID: c6798db71ccc47fea7434d36bbdcc073
I20260812 06:20:20.966557 24516 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:20.986114 24516 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:20.987253 24516 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:20.997534 24516 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886: Generated new TSK 0
I20260812 06:20:20.998281 24516 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:21.023986 24349 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:21.027006 24526 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:21.027030 24536 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:21.027035 24543 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:21.027709 24349 server_base.cc:1061] running on GCE node
I20260812 06:20:21.027891 24349 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:21.027948 24349 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:21.027973 24349 hybrid_clock.cc:648] HybridClock initialized: now 1786515621027973 us; error 0 us; skew 500 ppm
I20260812 06:20:21.029063 24349 webserver.cc:533] Webserver started at http://127.23.199.65:44547/ using document root <none> and password file <none>
I20260812 06:20:21.029266 24349 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:21.029335 24349 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:21.029418 24349 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:21.029839 24349 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/instance:
uuid: "f3ee0ef992494542becddb02e622b854"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-2kcd"
I20260812 06:20:21.031522 24349 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:20:21.032629 24550 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:21.032950 24349 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:21.033042 24349 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root
uuid: "f3ee0ef992494542becddb02e622b854"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-2kcd"
I20260812 06:20:21.033135 24349 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:21.054351 24349 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:21.054903 24349 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:21.055481 24349 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:21.056711 24349 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:21.056816 24349 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:21.056882 24349 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:21.056963 24349 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:21.063534 24349 rpc_server.cc:307] RPC server started. Bound to: 127.23.199.65:36709
I20260812 06:20:21.063737 24669 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.199.65:36709 every 8 connection(s)
I20260812 06:20:21.078328 24670 heartbeater.cc:344] Connected to a master server at 127.23.199.126:40561
I20260812 06:20:21.078734 24670 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:21.079317 24670 heartbeater.cc:507] Master 127.23.199.126:40561 requested a full tablet report, sending...
I20260812 06:20:21.080869 24415 ts_manager.cc:194] Registered new tserver with Master: f3ee0ef992494542becddb02e622b854 (127.23.199.65:36709)
I20260812 06:20:21.081121 24349 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016824733s
I20260812 06:20:21.082427 24415 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57958
I20260812 06:20:21.091660 24415 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57974:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:21.105822 24604 tablet_service.cc:1511] Processing CreateTablet for tablet 8b24016010e14e2c97dc3dc7e41cba9c (DEFAULT_TABLE table=heavy-update-compaction-test [id=d573387b57eb47608ce6cd6c64a92d1f]), partition=
I20260812 06:20:21.106367 24604 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8b24016010e14e2c97dc3dc7e41cba9c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:21.108951 24703 tablet_bootstrap.cc:492] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Bootstrap starting.
I20260812 06:20:21.110266 24703 tablet_bootstrap.cc:654] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:21.112166 24703 tablet_bootstrap.cc:492] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: No bootstrap required, opened a new log
I20260812 06:20:21.112293 24703 ts_tablet_manager.cc:1403] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Time spent bootstrapping tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:21.113036 24703 raft_consensus.cc:359] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f3ee0ef992494542becddb02e622b854" member_type: VOTER last_known_addr { host: "127.23.199.65" port: 36709 } }
I20260812 06:20:21.113184 24703 raft_consensus.cc:385] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:21.113241 24703 raft_consensus.cc:740] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f3ee0ef992494542becddb02e622b854, State: Initialized, Role: FOLLOWER
I20260812 06:20:21.113416 24703 consensus_queue.cc:260] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854 [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: "f3ee0ef992494542becddb02e622b854" member_type: VOTER last_known_addr { host: "127.23.199.65" port: 36709 } }
I20260812 06:20:21.113536 24703 raft_consensus.cc:399] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:21.113628 24703 raft_consensus.cc:493] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:21.113708 24703 raft_consensus.cc:3060] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:21.114809 24703 raft_consensus.cc:515] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f3ee0ef992494542becddb02e622b854" member_type: VOTER last_known_addr { host: "127.23.199.65" port: 36709 } }
I20260812 06:20:21.114984 24703 leader_election.cc:304] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854 [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: f3ee0ef992494542becddb02e622b854; no voters: 
I20260812 06:20:21.115227 24703 leader_election.cc:290] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:21.115361 24705 raft_consensus.cc:2804] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:21.115638 24705 raft_consensus.cc:697] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854 [term 1 LEADER]: Becoming Leader. State: Replica: f3ee0ef992494542becddb02e622b854, State: Running, Role: LEADER
I20260812 06:20:21.115659 24703 ts_tablet_manager.cc:1434] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Time spent starting tablet: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:21.116050 24670 heartbeater.cc:499] Master 127.23.199.126:40561 was elected leader, sending a full tablet report...
I20260812 06:20:21.116055 24705 consensus_queue.cc:237] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854 [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: "f3ee0ef992494542becddb02e622b854" member_type: VOTER last_known_addr { host: "127.23.199.65" port: 36709 } }
I20260812 06:20:21.119166 24415 catalog_manager.cc:5719] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854 reported cstate change: term changed from 0 to 1, leader changed from <none> to f3ee0ef992494542becddb02e622b854 (127.23.199.65). New cstate: current_term: 1 leader_uuid: "f3ee0ef992494542becddb02e622b854" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f3ee0ef992494542becddb02e622b854" member_type: VOTER last_known_addr { host: "127.23.199.65" port: 36709 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:21.183122 24349 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.021s	sys 0.004s
I20260812 06:20:21.314885 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushMRSOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=15.086190
I20260812 06:20:21.485042 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushMRSOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.170s	user 0.144s	sys 0.023s Metrics: {"bytes_written":9025566,"cfile_init":1,"compiler_manager_pool.queue_time_us":620,"delete_count":0,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":186,"dirs.run_wall_time_us":805,"drs_written":1,"lbm_read_time_us":146,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40256,"lbm_writes_lt_1ms":677,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":192256,"thread_start_us":151,"threads_started":1,"update_count":1100}
I20260812 06:20:21.486244 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling LogGCOp(8b24016010e14e2c97dc3dc7e41cba9c): free 20743880 bytes of WAL
I20260812 06:20:21.486595 24563 log_reader.cc:385] T 8b24016010e14e2c97dc3dc7e41cba9c: removed 2 log segments from log reader
I20260812 06:20:21.486691 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000001 (ops 1-6)
I20260812 06:20:21.486775 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000002 (ops 7-11)
I20260812 06:20:21.492580 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: LogGCOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.006s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:21.493100 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:21.507093 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.014s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3282155,"delete_count":0,"lbm_write_time_us":4656,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:20:21.507550 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling UndoDeltaBlockGCOp(8b24016010e14e2c97dc3dc7e41cba9c): 16411398 bytes on disk
I20260812 06:20:21.508097 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: UndoDeltaBlockGCOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.508500 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:21.620918 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.112s	user 0.082s	sys 0.029s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569849,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":872,"lbm_read_time_us":7272,"lbm_reads_lt_1ms":360,"lbm_write_time_us":20038,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"thread_start_us":292,"threads_started":5,"update_count":1500}
I20260812 06:20:21.621629 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=10.126437
I20260812 06:20:21.668184 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.046s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19101,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.668687 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:21.679319 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4050,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.679872 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:21.814745 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.135s	user 0.117s	sys 0.016s 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":816,"lbm_read_time_us":10254,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25732,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:20:21.815367 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=10.126437
I20260812 06:20:21.848511 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.033s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13658,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.849176 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:21.971119 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.122s	user 0.082s	sys 0.034s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569745,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":185,"lbm_read_time_us":7516,"lbm_reads_lt_1ms":363,"lbm_write_time_us":18439,"lbm_writes_lt_1ms":343,"mutex_wait_us":57,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":69888,"update_count":1500}
I20260812 06:20:21.971689 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=10.126437
I20260812 06:20:22.016546 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.045s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15068,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.017094 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:22.028258 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.028846 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:22.166973 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.138s	user 0.109s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":347,"lbm_read_time_us":10271,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25591,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:20:22.167483 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=10.126437
I20260812 06:20:22.216640 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.049s	user 0.007s	sys 0.032s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22576,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.217259 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:22.227973 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3962,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.228680 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:22.362562 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.134s	user 0.113s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":361,"lbm_read_time_us":8424,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28183,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:20:22.363125 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=10.126437
I20260812 06:20:22.418797 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.055s	user 0.013s	sys 0.035s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18433,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.419466 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:22.436764 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6472,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.437418 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:22.582216 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.145s	user 0.107s	sys 0.036s 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":706,"lbm_read_time_us":10830,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23041,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2000}
I20260812 06:20:22.582875 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=10.126437
I20260812 06:20:22.622290 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.039s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15291,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.622851 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:22.638774 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.016s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5805,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.639588 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:22.773285 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.133s	user 0.102s	sys 0.031s 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":795,"lbm_read_time_us":9662,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26054,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.774050 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=10.126437
I20260812 06:20:22.807186 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.033s	user 0.022s	sys 0.009s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14460,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.807947 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:22.821460 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5253,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.821916 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushMRSOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:22.857389 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushMRSOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.035s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":278,"dirs.run_wall_time_us":1637,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2053,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:22.858449 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling LogGCOp(8b24016010e14e2c97dc3dc7e41cba9c): free 120553326 bytes of WAL
I20260812 06:20:22.858749 24563 log_reader.cc:385] T 8b24016010e14e2c97dc3dc7e41cba9c: removed 12 log segments from log reader
I20260812 06:20:22.858816 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000003 (ops 12-16)
I20260812 06:20:22.858861 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000004 (ops 17-21)
I20260812 06:20:22.858887 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000005 (ops 22-26)
I20260812 06:20:22.858919 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000006 (ops 27-31)
I20260812 06:20:22.858955 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000007 (ops 32-36)
I20260812 06:20:22.858982 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000008 (ops 37-40)
I20260812 06:20:22.859009 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000009 (ops 41-45)
I20260812 06:20:22.859037 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000010 (ops 46-50)
I20260812 06:20:22.859066 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000011 (ops 51-54)
I20260812 06:20:22.859088 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000012 (ops 55-59)
I20260812 06:20:22.859115 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000013 (ops 60-64)
I20260812 06:20:22.859144 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000014 (ops 65-69)
I20260812 06:20:22.888653 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: LogGCOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:22.889185 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=4.173312
I20260812 06:20:22.909870 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.020s	user 0.014s	sys 0.005s Metrics: {"bytes_written":6276942,"delete_count":0,"lbm_write_time_us":8560,"lbm_writes_lt_1ms":156,"mutex_wait_us":201,"reinsert_count":0,"update_count":765}
I20260812 06:20:22.910471 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:22.919440 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":1928327,"delete_count":0,"lbm_write_time_us":2962,"lbm_writes_lt_1ms":50,"reinsert_count":0,"update_count":235}
I20260812 06:20:22.920076 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:23.095494 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.175s	user 0.151s	sys 0.023s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877284,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":179,"lbm_read_time_us":15047,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34956,"lbm_writes_lt_1ms":643,"mutex_wait_us":53,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10624,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:20:23.096283 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling UndoDeltaBlockGCOp(8b24016010e14e2c97dc3dc7e41cba9c): 473 bytes on disk
I20260812 06:20:23.096908 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: UndoDeltaBlockGCOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":97,"lbm_reads_lt_1ms":4}
I20260812 06:20:23.098847 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=14.095187
I20260812 06:20:23.141072 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.042s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19175,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.141569 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:23.156756 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5322,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.157238 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:23.307262 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.150s	user 0.103s	sys 0.039s 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":304,"lbm_read_time_us":9587,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31102,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27648,"update_count":2500}
I20260812 06:20:23.307932 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=14.095187
I20260812 06:20:23.359790 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.052s	user 0.029s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19009,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.360314 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:23.371871 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4257,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.372356 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:23.531648 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.159s	user 0.112s	sys 0.032s 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":327,"lbm_read_time_us":12191,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28923,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:23.532462 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=14.095187
I20260812 06:20:23.579056 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.046s	user 0.032s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20723,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.579520 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:23.739190 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.159s	user 0.095s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":886,"lbm_read_time_us":9748,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25830,"lbm_writes_lt_1ms":443,"mutex_wait_us":304,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":105216,"update_count":2000}
I20260812 06:20:23.739802 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=14.095187
I20260812 06:20:23.801002 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.061s	user 0.024s	sys 0.030s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20554,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.801563 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:23.812124 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4142,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.812611 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:23.981802 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.169s	user 0.124s	sys 0.043s 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":794,"lbm_read_time_us":12951,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30035,"lbm_writes_lt_1ms":543,"mutex_wait_us":286,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:20:23.982450 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=11.118625
I20260812 06:20:24.012058 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.029s	user 0.014s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13155,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:24.012588 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:24.026607 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5093,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.027122 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:24.181476 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.154s	user 0.116s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":152,"lbm_read_time_us":9918,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25334,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:20:24.182181 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=10.126437
I20260812 06:20:24.223443 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.041s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15359,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.223968 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:24.234570 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4030,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.235010 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushMRSOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:24.267432 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushMRSOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":192,"dirs.run_wall_time_us":1629,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1689,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:24.268152 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling LogGCOp(8b24016010e14e2c97dc3dc7e41cba9c): free 120553439 bytes of WAL
I20260812 06:20:24.268390 24563 log_reader.cc:385] T 8b24016010e14e2c97dc3dc7e41cba9c: removed 12 log segments from log reader
I20260812 06:20:24.268435 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000015 (ops 70-74)
I20260812 06:20:24.268465 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000016 (ops 75-79)
I20260812 06:20:24.268532 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000017 (ops 80-84)
I20260812 06:20:24.268571 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000018 (ops 85-89)
I20260812 06:20:24.268612 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000019 (ops 90-94)
I20260812 06:20:24.268653 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000020 (ops 95-99)
I20260812 06:20:24.268690 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000021 (ops 100-104)
I20260812 06:20:24.268726 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000022 (ops 105-108)
I20260812 06:20:24.268765 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000023 (ops 109-113)
I20260812 06:20:24.268826 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000024 (ops 114-118)
I20260812 06:20:24.268865 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000025 (ops 119-122)
I20260812 06:20:24.268904 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000026 (ops 123-127)
I20260812 06:20:24.296307 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: LogGCOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.028s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:20:24.296725 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling UndoDeltaBlockGCOp(8b24016010e14e2c97dc3dc7e41cba9c): 462 bytes on disk
I20260812 06:20:24.297308 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: UndoDeltaBlockGCOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:20:24.297820 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=3.181125
I20260812 06:20:24.310843 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5009,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:24.311296 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:24.321321 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3773,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.322934 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:24.498301 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.175s	user 0.137s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":317,"lbm_read_time_us":12124,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34350,"lbm_writes_lt_1ms":643,"mutex_wait_us":40,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":50432,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:20:24.498958 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=14.095187
I20260812 06:20:24.547279 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.048s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18694,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.547889 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:24.560340 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.012s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4838,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.561010 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:24.743904 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.183s	user 0.110s	sys 0.057s 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":183,"lbm_read_time_us":10341,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31712,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:24.744524 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=14.095187
I20260812 06:20:24.791450 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.047s	user 0.041s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20314,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.792061 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:24.802649 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.803113 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:24.962011 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.159s	user 0.115s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":403,"lbm_read_time_us":9919,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28864,"lbm_writes_lt_1ms":543,"mutex_wait_us":91,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:20:24.962653 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=14.095187
I20260812 06:20:25.012077 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.049s	user 0.017s	sys 0.029s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23389,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"spinlock_wait_cycles":20864,"update_count":2000}
I20260812 06:20:25.012691 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:25.028623 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5886,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.029500 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:25.225546 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.196s	user 0.146s	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":337,"lbm_read_time_us":11426,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35572,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:25.226291 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=14.095187
I20260812 06:20:25.282296 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.056s	user 0.030s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27419,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.282877 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:25.293648 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3953,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.294446 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:25.456084 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.161s	user 0.128s	sys 0.023s 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":676,"lbm_read_time_us":11095,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30671,"lbm_writes_lt_1ms":543,"mutex_wait_us":308,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:25.456861 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=14.095187
I20260812 06:20:25.511174 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.054s	user 0.029s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20269,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.511694 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=2.188937
I20260812 06:20:25.522445 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s 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:20:25.523124 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:25.698559 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.175s	user 0.116s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":323,"lbm_read_time_us":12389,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28738,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:20:25.699188 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=14.095187
I20260812 06:20:25.744284 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.045s	user 0.021s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19682,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.744933 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushMRSOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:25.777400 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushMRSOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.032s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":1362,"drs_written":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1792,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:25.778043 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling LogGCOp(8b24016010e14e2c97dc3dc7e41cba9c): free 132571585 bytes of WAL
I20260812 06:20:25.778262 24563 log_reader.cc:385] T 8b24016010e14e2c97dc3dc7e41cba9c: removed 13 log segments from log reader
I20260812 06:20:25.778306 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000027 (ops 128-132)
I20260812 06:20:25.778334 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000028 (ops 133-137)
I20260812 06:20:25.778394 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000029 (ops 138-142)
I20260812 06:20:25.778455 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000030 (ops 143-146)
I20260812 06:20:25.778494 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000031 (ops 147-151)
I20260812 06:20:25.778537 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000032 (ops 152-156)
I20260812 06:20:25.778575 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000033 (ops 157-160)
I20260812 06:20:25.778612 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000034 (ops 161-165)
I20260812 06:20:25.778650 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000035 (ops 166-170)
I20260812 06:20:25.778689 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000036 (ops 171-175)
I20260812 06:20:25.778728 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000037 (ops 176-180)
I20260812 06:20:25.778766 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000038 (ops 181-185)
I20260812 06:20:25.778803 24563 log.cc:1079] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/8b24016010e14e2c97dc3dc7e41cba9c/wal-000000039 (ops 186-190)
I20260812 06:20:25.809623 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: LogGCOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.031s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:20:25.810736 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling UndoDeltaBlockGCOp(8b24016010e14e2c97dc3dc7e41cba9c): 493 bytes on disk
I20260812 06:20:25.811138 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: UndoDeltaBlockGCOp(8b24016010e14e2c97dc3dc7e41cba9c) 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:20:25.811766 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=5.165500
I20260812 06:20:25.828166 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":6810258,"delete_count":0,"lbm_write_time_us":6784,"lbm_writes_lt_1ms":169,"reinsert_count":0,"update_count":830}
I20260812 06:20:25.828603 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:25.837951 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":1395002,"delete_count":0,"lbm_write_time_us":2540,"lbm_writes_lt_1ms":37,"reinsert_count":0,"update_count":170}
I20260812 06:20:25.838757 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:26.025019 24349 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.842s	user 1.818s	sys 0.138s
I20260812 06:20:26.043375 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.204s	user 0.141s	sys 0.061s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877158,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":14169,"lbm_reads_lt_1ms":661,"lbm_write_time_us":38512,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:20:26.044090 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=14.095187
I20260812 06:20:26.090282 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: FlushDeltaMemStoresOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.046s	user 0.026s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21358,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.090814 24674 maintenance_manager.cc:419] P f3ee0ef992494542becddb02e622b854: Scheduling MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c): perf score=1.000000
I20260812 06:20:26.139376 24349 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.114s	user 0.001s	sys 0.000s
I20260812 06:20:26.140048 24349 tablet_server.cc:179] TabletServer@127.23.199.65:0 shutting down...
I20260812 06:20:26.224135 24563 maintenance_manager.cc:643] P f3ee0ef992494542becddb02e622b854: MajorDeltaCompactionOp(8b24016010e14e2c97dc3dc7e41cba9c) complete. Timing: real 0.133s	user 0.081s	sys 0.052s 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":1701,"lbm_read_time_us":9562,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27664,"lbm_writes_lt_1ms":443,"mutex_wait_us":89,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:20:26.225845 24349 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:26.226277 24349 tablet_replica.cc:333] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854: stopping tablet replica
I20260812 06:20:26.226538 24349 raft_consensus.cc:2243] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:26.226785 24349 raft_consensus.cc:2272] T 8b24016010e14e2c97dc3dc7e41cba9c P f3ee0ef992494542becddb02e622b854 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:26.242772 24349 tablet_server.cc:196] TabletServer@127.23.199.65:0 shutdown complete.
I20260812 06:20:26.264191 24349 master.cc:562] Master@127.23.199.126:40561 shutting down...
I20260812 06:20:26.268671 24349 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:26.268908 24349 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:26.268977 24349 tablet_replica.cc:333] T 00000000000000000000000000000000 P b5746108ab064e2dbcb62282e8c93886: stopping tablet replica
I20260812 06:20:26.281159 24349 master.cc:584] Master@127.23.199.126:40561 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5482 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:26.374384 24349 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.23.199.126:44835
I20260812 06:20:26.374743 24349 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:26.376910 24753 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:26.376938 24744 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:20:26.377032 24349 server_base.cc:1061] running on GCE node
W20260812 06:20:26.376945 24743 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:26.377306 24349 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:26.377351 24349 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:26.377373 24349 hybrid_clock.cc:648] HybridClock initialized: now 1786515626377373 us; error 0 us; skew 500 ppm
I20260812 06:20:26.378245 24349 webserver.cc:533] Webserver started at http://127.23.199.126:38369/ using document root <none> and password file <none>
I20260812 06:20:26.378439 24349 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:26.378489 24349 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:26.378573 24349 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:26.378996 24349 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/master-0-root/instance:
uuid: "a59eafd4c6ef4ac1add55b2eca8acb30"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-2kcd"
I20260812 06:20:26.380573 24349 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:26.381651 24760 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.381875 24349 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:26.381973 24349 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/master-0-root
uuid: "a59eafd4c6ef4ac1add55b2eca8acb30"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-2kcd"
I20260812 06:20:26.382066 24349 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:26.396168 24349 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:26.396580 24349 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:26.400651 24349 rpc_server.cc:307] RPC server started. Bound to: 127.23.199.126:44835
I20260812 06:20:26.404526 24864 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.199.126:44835 every 8 connection(s)
I20260812 06:20:26.405061 24865 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:26.419062 24865 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30: Bootstrap starting.
I20260812 06:20:26.419962 24865 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:26.421144 24865 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30: No bootstrap required, opened a new log
I20260812 06:20:26.421562 24865 raft_consensus.cc:359] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a59eafd4c6ef4ac1add55b2eca8acb30" member_type: VOTER }
I20260812 06:20:26.421649 24865 raft_consensus.cc:385] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:26.421706 24865 raft_consensus.cc:740] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a59eafd4c6ef4ac1add55b2eca8acb30, State: Initialized, Role: FOLLOWER
I20260812 06:20:26.421868 24865 consensus_queue.cc:260] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [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: "a59eafd4c6ef4ac1add55b2eca8acb30" member_type: VOTER }
I20260812 06:20:26.421949 24865 raft_consensus.cc:399] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:26.422008 24865 raft_consensus.cc:493] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:26.422080 24865 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:26.422791 24865 raft_consensus.cc:515] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a59eafd4c6ef4ac1add55b2eca8acb30" member_type: VOTER }
I20260812 06:20:26.422942 24865 leader_election.cc:304] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [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: a59eafd4c6ef4ac1add55b2eca8acb30; no voters: 
I20260812 06:20:26.423153 24865 leader_election.cc:290] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:26.423300 24871 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:26.423533 24871 raft_consensus.cc:697] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [term 1 LEADER]: Becoming Leader. State: Replica: a59eafd4c6ef4ac1add55b2eca8acb30, State: Running, Role: LEADER
I20260812 06:20:26.423604 24865 sys_catalog.cc:565] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:26.423697 24871 consensus_queue.cc:237] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [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: "a59eafd4c6ef4ac1add55b2eca8acb30" member_type: VOTER }
I20260812 06:20:26.424127 24883 sys_catalog.cc:455] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a59eafd4c6ef4ac1add55b2eca8acb30" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a59eafd4c6ef4ac1add55b2eca8acb30" member_type: VOTER } }
I20260812 06:20:26.424147 24884 sys_catalog.cc:455] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [sys.catalog]: SysCatalogTable state changed. Reason: New leader a59eafd4c6ef4ac1add55b2eca8acb30. Latest consensus state: current_term: 1 leader_uuid: "a59eafd4c6ef4ac1add55b2eca8acb30" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a59eafd4c6ef4ac1add55b2eca8acb30" member_type: VOTER } }
I20260812 06:20:26.424237 24883 sys_catalog.cc:458] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:26.424242 24884 sys_catalog.cc:458] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:26.424767 24890 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:26.425459 24890 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:26.425644 24349 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:26.427284 24890 catalog_manager.cc:1383] Generated new cluster ID: 4020bfe913a24e57a599b84b1935efb3
I20260812 06:20:26.427345 24890 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:26.435313 24890 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:26.435945 24890 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:26.453296 24890 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30: Generated new TSK 0
I20260812 06:20:26.453526 24890 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:26.458132 24349 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:26.460269 24912 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:26.460326 24913 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:26.460346 24915 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:26.460523 24349 server_base.cc:1061] running on GCE node
I20260812 06:20:26.460723 24349 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:26.460776 24349 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:26.460829 24349 hybrid_clock.cc:648] HybridClock initialized: now 1786515626460828 us; error 0 us; skew 500 ppm
I20260812 06:20:26.461728 24349 webserver.cc:533] Webserver started at http://127.23.199.65:36187/ using document root <none> and password file <none>
I20260812 06:20:26.461915 24349 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:26.461984 24349 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:26.462064 24349 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:26.462481 24349 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/instance:
uuid: "f69b83b38abd4fc4bcdfdde0f21bde83"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-2kcd"
I20260812 06:20:26.463994 24349 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:26.464983 24923 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.465243 24349 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:26.465332 24349 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root
uuid: "f69b83b38abd4fc4bcdfdde0f21bde83"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-2kcd"
I20260812 06:20:26.465428 24349 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:26.472604 24349 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:26.473016 24349 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:26.473325 24349 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:26.473795 24349 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:26.473855 24349 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.473903 24349 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:26.473953 24349 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.478391 24349 rpc_server.cc:307] RPC server started. Bound to: 127.23.199.65:46235
I20260812 06:20:26.478427 25041 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.199.65:46235 every 8 connection(s)
I20260812 06:20:26.488344 25044 heartbeater.cc:344] Connected to a master server at 127.23.199.126:44835
I20260812 06:20:26.488477 25044 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:26.488751 25044 heartbeater.cc:507] Master 127.23.199.126:44835 requested a full tablet report, sending...
I20260812 06:20:26.489518 24801 ts_manager.cc:194] Registered new tserver with Master: f69b83b38abd4fc4bcdfdde0f21bde83 (127.23.199.65:46235)
I20260812 06:20:26.489965 24349 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011116987s
I20260812 06:20:26.490361 24801 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:40216
I20260812 06:20:26.496757 24801 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:40224:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:26.505894 24974 tablet_service.cc:1511] Processing CreateTablet for tablet 36321aa524b54e569d8e9e48ebff8455 (DEFAULT_TABLE table=heavy-update-compaction-test [id=4a427703c360462785e14ffcc19a3765]), partition=
I20260812 06:20:26.506207 24974 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 36321aa524b54e569d8e9e48ebff8455. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:26.508397 25070 tablet_bootstrap.cc:492] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Bootstrap starting.
I20260812 06:20:26.509351 25070 tablet_bootstrap.cc:654] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:26.510524 25070 tablet_bootstrap.cc:492] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: No bootstrap required, opened a new log
I20260812 06:20:26.510620 25070 ts_tablet_manager.cc:1403] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:26.511139 25070 raft_consensus.cc:359] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f69b83b38abd4fc4bcdfdde0f21bde83" member_type: VOTER last_known_addr { host: "127.23.199.65" port: 46235 } }
I20260812 06:20:26.511251 25070 raft_consensus.cc:385] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:26.511296 25070 raft_consensus.cc:740] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f69b83b38abd4fc4bcdfdde0f21bde83, State: Initialized, Role: FOLLOWER
I20260812 06:20:26.511435 25070 consensus_queue.cc:260] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83 [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: "f69b83b38abd4fc4bcdfdde0f21bde83" member_type: VOTER last_known_addr { host: "127.23.199.65" port: 46235 } }
I20260812 06:20:26.511528 25070 raft_consensus.cc:399] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:26.511572 25070 raft_consensus.cc:493] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:26.511628 25070 raft_consensus.cc:3060] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:26.512349 25070 raft_consensus.cc:515] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f69b83b38abd4fc4bcdfdde0f21bde83" member_type: VOTER last_known_addr { host: "127.23.199.65" port: 46235 } }
I20260812 06:20:26.512502 25070 leader_election.cc:304] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83 [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: f69b83b38abd4fc4bcdfdde0f21bde83; no voters: 
I20260812 06:20:26.512717 25070 leader_election.cc:290] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:26.512918 25076 raft_consensus.cc:2804] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:26.513154 25070 ts_tablet_manager.cc:1434] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:26.513162 25044 heartbeater.cc:499] Master 127.23.199.126:44835 was elected leader, sending a full tablet report...
I20260812 06:20:26.513164 25076 raft_consensus.cc:697] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83 [term 1 LEADER]: Becoming Leader. State: Replica: f69b83b38abd4fc4bcdfdde0f21bde83, State: Running, Role: LEADER
I20260812 06:20:26.513428 25076 consensus_queue.cc:237] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83 [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: "f69b83b38abd4fc4bcdfdde0f21bde83" member_type: VOTER last_known_addr { host: "127.23.199.65" port: 46235 } }
I20260812 06:20:26.514895 24801 catalog_manager.cc:5719] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83 reported cstate change: term changed from 0 to 1, leader changed from <none> to f69b83b38abd4fc4bcdfdde0f21bde83 (127.23.199.65). New cstate: current_term: 1 leader_uuid: "f69b83b38abd4fc4bcdfdde0f21bde83" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f69b83b38abd4fc4bcdfdde0f21bde83" member_type: VOTER last_known_addr { host: "127.23.199.65" port: 46235 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:26.574637 24349 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.015s	sys 0.008s
I20260812 06:20:26.729357 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushMRSOp(36321aa524b54e569d8e9e48ebff8455): perf score=19.054940
I20260812 06:20:26.886821 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushMRSOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.157s	user 0.111s	sys 0.044s Metrics: {"bytes_written":13127981,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":990,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38187,"lbm_writes_lt_1ms":777,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":768,"update_count":1600}
I20260812 06:20:26.887602 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling LogGCOp(36321aa524b54e569d8e9e48ebff8455): free 20743880 bytes of WAL
I20260812 06:20:26.887826 24933 log_reader.cc:385] T 36321aa524b54e569d8e9e48ebff8455: removed 2 log segments from log reader
I20260812 06:20:26.887885 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000001 (ops 1-6)
I20260812 06:20:26.887929 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000002 (ops 7-11)
I20260812 06:20:26.892722 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: LogGCOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:26.893078 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling UndoDeltaBlockGCOp(36321aa524b54e569d8e9e48ebff8455): 16411395 bytes on disk
I20260812 06:20:26.893453 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: UndoDeltaBlockGCOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.893875 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:26.914402 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.020s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692410,"delete_count":0,"lbm_write_time_us":5665,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.914853 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:26.939471 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.024s	user 0.008s	sys 0.014s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5152,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.940104 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:27.138134 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.198s	user 0.139s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774796,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":538,"lbm_read_time_us":12961,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29810,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":315,"threads_started":5,"update_count":2500}
I20260812 06:20:27.138710 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=14.095187
I20260812 06:20:27.187999 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.049s	user 0.022s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21660,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.188506 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:27.200964 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.012s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4519,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.201515 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:27.382880 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.181s	user 0.116s	sys 0.057s 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":647,"lbm_read_time_us":12336,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28286,"lbm_writes_lt_1ms":543,"mutex_wait_us":289,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2500}
I20260812 06:20:27.383628 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=14.095187
I20260812 06:20:27.427347 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.044s	user 0.026s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18933,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.427876 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:27.439860 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4134,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.440397 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:27.596354 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.156s	user 0.115s	sys 0.032s 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":272,"lbm_read_time_us":10746,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29362,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:20:27.596956 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=14.095187
I20260812 06:20:27.649310 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.052s	user 0.033s	sys 0.017s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21922,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.649731 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:27.660730 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4082,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.661365 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:27.820138 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.159s	user 0.118s	sys 0.036s 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":244,"lbm_read_time_us":11499,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31168,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2500}
I20260812 06:20:27.820842 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=11.118625
I20260812 06:20:27.859134 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.038s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16214,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:27.860006 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:27.875453 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5448,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:27.876003 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:28.013134 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.137s	user 0.094s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1346,"lbm_read_time_us":9899,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27404,"lbm_writes_lt_1ms":443,"mutex_wait_us":415,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2000}
I20260812 06:20:28.013929 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=11.118625
I20260812 06:20:28.058677 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.045s	user 0.026s	sys 0.013s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15433,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:28.059398 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:28.081660 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.022s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5201,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.082213 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:28.096841 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.014s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5649,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.097308 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushMRSOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:28.132954 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushMRSOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.035s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":191,"dirs.run_wall_time_us":1390,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1354,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:28.133571 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling LogGCOp(36321aa524b54e569d8e9e48ebff8455): free 120553336 bytes of WAL
I20260812 06:20:28.133795 24933 log_reader.cc:385] T 36321aa524b54e569d8e9e48ebff8455: removed 12 log segments from log reader
I20260812 06:20:28.133839 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000003 (ops 12-16)
I20260812 06:20:28.133868 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000004 (ops 17-21)
I20260812 06:20:28.133913 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000005 (ops 22-26)
I20260812 06:20:28.133955 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000006 (ops 27-30)
I20260812 06:20:28.133982 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000007 (ops 31-35)
I20260812 06:20:28.134038 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000008 (ops 36-40)
I20260812 06:20:28.134095 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000009 (ops 41-45)
I20260812 06:20:28.134131 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000010 (ops 46-50)
I20260812 06:20:28.134167 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000011 (ops 51-54)
I20260812 06:20:28.134205 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000012 (ops 55-59)
I20260812 06:20:28.134243 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000013 (ops 60-64)
I20260812 06:20:28.134281 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000014 (ops 65-69)
I20260812 06:20:28.159966 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: LogGCOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:28.160432 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling UndoDeltaBlockGCOp(36321aa524b54e569d8e9e48ebff8455): 462 bytes on disk
I20260812 06:20:28.160960 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: UndoDeltaBlockGCOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:20:28.161474 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:28.178668 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.017s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4617,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.179117 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:28.193538 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.014s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5668,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.194075 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:28.435614 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.241s	user 0.160s	sys 0.076s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979862,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":844,"lbm_read_time_us":15612,"lbm_reads_lt_1ms":775,"lbm_write_time_us":41915,"lbm_writes_lt_1ms":743,"mutex_wait_us":318,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3456,"thread_start_us":90,"threads_started":1,"update_count":3500}
I20260812 06:20:28.436435 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=18.063937
I20260812 06:20:28.490624 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.054s	user 0.045s	sys 0.007s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":24133,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:28.491170 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:28.507047 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6401,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.507592 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:28.671047 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.163s	user 0.119s	sys 0.042s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1873,"lbm_read_time_us":11504,"lbm_reads_lt_1ms":664,"lbm_write_time_us":33430,"lbm_writes_lt_1ms":643,"mutex_wait_us":816,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":3000}
I20260812 06:20:28.671893 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=14.095187
I20260812 06:20:28.715364 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.043s	user 0.023s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19305,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.715915 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:28.735986 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.020s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6342,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.736466 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:28.900466 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.164s	user 0.124s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":590,"lbm_read_time_us":9295,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31349,"lbm_writes_lt_1ms":543,"mutex_wait_us":327,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:20:28.901194 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=14.095187
I20260812 06:20:28.950937 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.050s	user 0.033s	sys 0.009s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20357,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.951576 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:29.096401 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.145s	user 0.088s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1057,"lbm_read_time_us":9706,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23048,"lbm_writes_lt_1ms":443,"mutex_wait_us":259,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:20:29.097116 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=14.095187
I20260812 06:20:29.150233 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.053s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24593,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.150854 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:29.162782 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4108,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.163729 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:29.363555 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.200s	user 0.110s	sys 0.084s 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":949,"lbm_read_time_us":14952,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30455,"lbm_writes_lt_1ms":543,"mutex_wait_us":341,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:20:29.364284 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=14.095187
I20260812 06:20:29.412559 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.048s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21144,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.413038 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:29.425881 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.013s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4471,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.426436 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:29.590632 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.164s	user 0.115s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":391,"lbm_read_time_us":9504,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31459,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:29.591410 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=14.095187
I20260812 06:20:29.643524 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.052s	user 0.018s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19908,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.644160 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:29.660168 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6075,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.660982 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushMRSOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:29.698894 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushMRSOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.038s	user 0.032s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1459,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2361,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:29.699749 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling LogGCOp(36321aa524b54e569d8e9e48ebff8455): free 133024385 bytes of WAL
I20260812 06:20:29.699980 24933 log_reader.cc:385] T 36321aa524b54e569d8e9e48ebff8455: removed 13 log segments from log reader
I20260812 06:20:29.700033 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000015 (ops 70-74)
I20260812 06:20:29.700074 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000016 (ops 75-79)
I20260812 06:20:29.700109 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000017 (ops 80-84)
I20260812 06:20:29.700138 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000018 (ops 85-89)
I20260812 06:20:29.700169 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000019 (ops 90-94)
I20260812 06:20:29.700203 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000020 (ops 95-99)
I20260812 06:20:29.700235 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000021 (ops 100-104)
I20260812 06:20:29.700263 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000022 (ops 105-109)
I20260812 06:20:29.700294 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000023 (ops 110-114)
I20260812 06:20:29.700323 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000024 (ops 115-118)
I20260812 06:20:29.700353 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000025 (ops 119-123)
I20260812 06:20:29.700387 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000026 (ops 124-128)
I20260812 06:20:29.700421 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000027 (ops 129-133)
I20260812 06:20:29.733640 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: LogGCOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.034s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:20:29.734123 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling UndoDeltaBlockGCOp(36321aa524b54e569d8e9e48ebff8455): 492 bytes on disk
I20260812 06:20:29.734777 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: UndoDeltaBlockGCOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":93,"lbm_reads_lt_1ms":4}
I20260812 06:20:29.735455 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=4.173312
I20260812 06:20:29.767314 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.032s	user 0.006s	sys 0.023s Metrics: {"bytes_written":5825681,"delete_count":0,"lbm_write_time_us":7075,"lbm_writes_lt_1ms":145,"reinsert_count":0,"update_count":710}
I20260812 06:20:29.767951 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.196750
I20260812 06:20:29.779135 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":2379604,"delete_count":0,"lbm_write_time_us":3652,"lbm_writes_lt_1ms":61,"reinsert_count":0,"update_count":290}
I20260812 06:20:29.779709 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:30.040199 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.260s	user 0.152s	sys 0.108s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979712,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1178,"lbm_read_time_us":16814,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42140,"lbm_writes_lt_1ms":743,"mutex_wait_us":41,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18176,"thread_start_us":98,"threads_started":1,"update_count":3500}
I20260812 06:20:30.044281 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=18.063937
I20260812 06:20:30.110404 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.066s	user 0.043s	sys 0.016s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":27483,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:30.110960 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:30.123013 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4051,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.123701 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:30.340955 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.217s	user 0.156s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":667,"lbm_read_time_us":14528,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34519,"lbm_writes_lt_1ms":643,"mutex_wait_us":374,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":3000}
I20260812 06:20:30.341753 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=14.095187
I20260812 06:20:30.387961 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.046s	user 0.022s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20617,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.388492 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:30.399260 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4401,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.399935 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:30.573010 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.173s	user 0.099s	sys 0.070s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":325,"lbm_read_time_us":12197,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28861,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:20:30.573618 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=14.095187
I20260812 06:20:30.625497 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.052s	user 0.040s	sys 0.009s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20537,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.626128 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:30.637261 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4205,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.637939 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:30.826030 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.188s	user 0.126s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":274,"lbm_read_time_us":12475,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30557,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2500}
I20260812 06:20:30.826795 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=14.095187
I20260812 06:20:30.888659 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.062s	user 0.035s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21375,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.889312 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:30.900662 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4630,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.901166 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:31.081171 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.180s	user 0.120s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":194,"lbm_read_time_us":13494,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28023,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":38528,"update_count":2500}
I20260812 06:20:31.081884 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=14.095187
I20260812 06:20:31.140153 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.058s	user 0.032s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19983,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.140707 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:31.151118 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4179,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.151521 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushMRSOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:31.198462 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushMRSOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.047s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":182,"dirs.run_wall_time_us":1432,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1508,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:31.199178 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling LogGCOp(36321aa524b54e569d8e9e48ebff8455): free 111786557 bytes of WAL
I20260812 06:20:31.199407 24933 log_reader.cc:385] T 36321aa524b54e569d8e9e48ebff8455: removed 11 log segments from log reader
I20260812 06:20:31.199451 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000028 (ops 134-138)
I20260812 06:20:31.199479 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000029 (ops 139-142)
I20260812 06:20:31.199533 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000030 (ops 143-147)
I20260812 06:20:31.199575 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000031 (ops 148-152)
I20260812 06:20:31.199640 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000032 (ops 153-157)
I20260812 06:20:31.199688 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000033 (ops 158-162)
I20260812 06:20:31.199733 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000034 (ops 163-167)
I20260812 06:20:31.199769 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000035 (ops 168-172)
I20260812 06:20:31.199808 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000036 (ops 173-177)
I20260812 06:20:31.199851 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000037 (ops 178-182)
I20260812 06:20:31.199893 24933 log.cc:1079] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: Deleting log segment in path: /tmp/dist-test-taskrzkhbN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620881737-24349-0/minicluster-data/ts-0-root/wals/36321aa524b54e569d8e9e48ebff8455/wal-000000038 (ops 183-186)
I20260812 06:20:31.225471 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: LogGCOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:31.226073 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=3.181125
I20260812 06:20:31.246093 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.020s	user 0.008s	sys 0.009s Metrics: {"bytes_written":4471876,"delete_count":0,"lbm_write_time_us":7181,"lbm_writes_lt_1ms":112,"reinsert_count":0,"update_count":545}
I20260812 06:20:31.246611 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=2.188937
I20260812 06:20:31.256177 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3733433,"delete_count":0,"lbm_write_time_us":3702,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:20:31.256875 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling UndoDeltaBlockGCOp(36321aa524b54e569d8e9e48ebff8455): 448 bytes on disk
I20260812 06:20:31.257373 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: UndoDeltaBlockGCOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:20:31.258306 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:31.487672 24349 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.913s	user 1.819s	sys 0.216s
I20260812 06:20:31.500501 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.242s	user 0.153s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979742,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":473,"lbm_read_time_us":16698,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38425,"lbm_writes_lt_1ms":743,"mutex_wait_us":53,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":70144,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:20:31.501243 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455): perf score=18.063937
I20260812 06:20:31.547864 24349 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.060s	user 0.001s	sys 0.000s
I20260812 06:20:31.548465 24349 tablet_server.cc:179] TabletServer@127.23.199.65:0 shutting down...
I20260812 06:20:31.553073 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: FlushDeltaMemStoresOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.051s	user 0.031s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":23190,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:31.553668 25045 maintenance_manager.cc:419] P f69b83b38abd4fc4bcdfdde0f21bde83: Scheduling MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455): perf score=1.000000
I20260812 06:20:31.688715 24933 maintenance_manager.cc:643] P f69b83b38abd4fc4bcdfdde0f21bde83: MajorDeltaCompactionOp(36321aa524b54e569d8e9e48ebff8455) complete. Timing: real 0.135s	user 0.091s	sys 0.044s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":501,"cfile_cache_miss_bytes":20512182,"cfile_init":3,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":265,"lbm_read_time_us":7642,"lbm_reads_lt_1ms":513,"lbm_write_time_us":23711,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:20:31.689502 24349 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:31.689749 24349 tablet_replica.cc:333] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83: stopping tablet replica
I20260812 06:20:31.689908 24349 raft_consensus.cc:2243] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.690102 24349 raft_consensus.cc:2272] T 36321aa524b54e569d8e9e48ebff8455 P f69b83b38abd4fc4bcdfdde0f21bde83 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.704245 24349 tablet_server.cc:196] TabletServer@127.23.199.65:0 shutdown complete.
I20260812 06:20:31.736554 24349 master.cc:562] Master@127.23.199.126:44835 shutting down...
I20260812 06:20:31.740090 24349 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.740370 24349 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.740451 24349 tablet_replica.cc:333] T 00000000000000000000000000000000 P a59eafd4c6ef4ac1add55b2eca8acb30: stopping tablet replica
I20260812 06:20:31.753207 24349 master.cc:584] Master@127.23.199.126:44835 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5480 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10963 ms total)

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