[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:25.799918 19914 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.114.190:35107
I20260812 06:18:25.801213 19914 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:25.802000 19914 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:25.810223 19922 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:25.810330 19921 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:25.810520 19928 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:25.810717 19914 server_base.cc:1061] running on GCE node
I20260812 06:18:25.811447 19914 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:25.811566 19914 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:25.811648 19914 hybrid_clock.cc:648] HybridClock initialized: now 1786515505811644 us; error 0 us; skew 500 ppm
I20260812 06:18:25.814344 19914 webserver.cc:533] Webserver started at http://127.19.114.190:34875/ using document root <none> and password file <none>
I20260812 06:18:25.815192 19914 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:25.815284 19914 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:25.815640 19914 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:25.817615 19914 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/master-0-root/instance:
uuid: "249e84130d0d44b4bfcbde4bfbb64581"
format_stamp: "Formatted at 2026-08-12 06:18:25 on dist-test-slave-1nl6"
I20260812 06:18:25.822132 19914 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.006s	sys 0.000s
I20260812 06:18:25.825063 19936 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:25.826417 19914 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:25.826606 19914 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/master-0-root
uuid: "249e84130d0d44b4bfcbde4bfbb64581"
format_stamp: "Formatted at 2026-08-12 06:18:25 on dist-test-slave-1nl6"
I20260812 06:18:25.826745 19914 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:25.855162 19914 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:25.856142 19914 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:25.856377 19914 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:25.866228 19914 rpc_server.cc:307] RPC server started. Bound to: 127.19.114.190:35107
I20260812 06:18:25.866328 20026 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.114.190:35107 every 8 connection(s)
I20260812 06:18:25.869640 20027 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:25.876777 20027 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581: Bootstrap starting.
I20260812 06:18:25.880003 20027 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:25.881204 20027 log.cc:826] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:25.884008 20027 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581: No bootstrap required, opened a new log
I20260812 06:18:25.887449 20027 raft_consensus.cc:359] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "249e84130d0d44b4bfcbde4bfbb64581" member_type: VOTER }
I20260812 06:18:25.887692 20027 raft_consensus.cc:385] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:25.887740 20027 raft_consensus.cc:740] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 249e84130d0d44b4bfcbde4bfbb64581, State: Initialized, Role: FOLLOWER
I20260812 06:18:25.888396 20027 consensus_queue.cc:260] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [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: "249e84130d0d44b4bfcbde4bfbb64581" member_type: VOTER }
I20260812 06:18:25.888578 20027 raft_consensus.cc:399] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:25.888625 20027 raft_consensus.cc:493] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:25.888729 20027 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:25.889715 20027 raft_consensus.cc:515] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "249e84130d0d44b4bfcbde4bfbb64581" member_type: VOTER }
I20260812 06:18:25.890209 20027 leader_election.cc:304] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [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: 249e84130d0d44b4bfcbde4bfbb64581; no voters: 
I20260812 06:18:25.890581 20027 leader_election.cc:290] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:25.890981 20031 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:25.891386 20031 raft_consensus.cc:697] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [term 1 LEADER]: Becoming Leader. State: Replica: 249e84130d0d44b4bfcbde4bfbb64581, State: Running, Role: LEADER
I20260812 06:18:25.891985 20027 sys_catalog.cc:565] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:25.891999 20031 consensus_queue.cc:237] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [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: "249e84130d0d44b4bfcbde4bfbb64581" member_type: VOTER }
I20260812 06:18:25.895031 19914 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:25.895035 20032 sys_catalog.cc:455] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "249e84130d0d44b4bfcbde4bfbb64581" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "249e84130d0d44b4bfcbde4bfbb64581" member_type: VOTER } }
I20260812 06:18:25.895272 20032 sys_catalog.cc:458] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:25.895048 20033 sys_catalog.cc:455] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 249e84130d0d44b4bfcbde4bfbb64581. Latest consensus state: current_term: 1 leader_uuid: "249e84130d0d44b4bfcbde4bfbb64581" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "249e84130d0d44b4bfcbde4bfbb64581" member_type: VOTER } }
I20260812 06:18:25.895468 20033 sys_catalog.cc:458] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [sys.catalog]: This master's current role is: LEADER
W20260812 06:18:25.898751 20052 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:25.898954 20052 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:25.899036 20053 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:25.899919 20053 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:25.906227 20053 catalog_manager.cc:1383] Generated new cluster ID: 0a52396bbedc4ba0970cba2a836e6b10
I20260812 06:18:25.906352 20053 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:25.926059 20053 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:25.927162 20053 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:25.935041 20053 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581: Generated new TSK 0
I20260812 06:18:25.935853 20053 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:25.960826 19914 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:25.964082 20060 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:25.964218 20061 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:25.964164 20063 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:25.964715 19914 server_base.cc:1061] running on GCE node
I20260812 06:18:25.964913 19914 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:25.964962 19914 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:25.964986 19914 hybrid_clock.cc:648] HybridClock initialized: now 1786515505964986 us; error 0 us; skew 500 ppm
I20260812 06:18:25.966055 19914 webserver.cc:533] Webserver started at http://127.19.114.129:45053/ using document root <none> and password file <none>
I20260812 06:18:25.966240 19914 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:25.966310 19914 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:25.966392 19914 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:25.966857 19914 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/instance:
uuid: "b4ffb4e0895a4643b9dd9494c7b19081"
format_stamp: "Formatted at 2026-08-12 06:18:25 on dist-test-slave-1nl6"
I20260812 06:18:25.968854 19914 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.001s	sys 0.001s
I20260812 06:18:25.970302 20074 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:25.970695 19914 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:25.970784 19914 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root
uuid: "b4ffb4e0895a4643b9dd9494c7b19081"
format_stamp: "Formatted at 2026-08-12 06:18:25 on dist-test-slave-1nl6"
I20260812 06:18:25.970858 19914 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:26.007802 19914 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:26.008315 19914 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:26.008816 19914 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:26.009730 19914 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:26.009856 19914 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:26.009968 19914 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:26.010252 19914 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:26.019043 19914 rpc_server.cc:307] RPC server started. Bound to: 127.19.114.129:38243
I20260812 06:18:26.019114 20187 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.114.129:38243 every 8 connection(s)
I20260812 06:18:26.035988 20188 heartbeater.cc:344] Connected to a master server at 127.19.114.190:35107
I20260812 06:18:26.036353 20188 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:26.037050 20188 heartbeater.cc:507] Master 127.19.114.190:35107 requested a full tablet report, sending...
I20260812 06:18:26.039151 19966 ts_manager.cc:194] Registered new tserver with Master: b4ffb4e0895a4643b9dd9494c7b19081 (127.19.114.129:38243)
I20260812 06:18:26.039317 19914 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.019458758s
I20260812 06:18:26.040874 19966 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:53602
I20260812 06:18:26.053817 19966 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:53610:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:26.072306 20123 tablet_service.cc:1511] Processing CreateTablet for tablet e75716b83e11459abd3bc3597d1d500f (DEFAULT_TABLE table=heavy-update-compaction-test [id=c76d9e69111f4ced8dd154e9321efb7a]), partition=
I20260812 06:18:26.073043 20123 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e75716b83e11459abd3bc3597d1d500f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:26.082038 20209 tablet_bootstrap.cc:492] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Bootstrap starting.
I20260812 06:18:26.083602 20209 tablet_bootstrap.cc:654] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:26.090710 20209 tablet_bootstrap.cc:492] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: No bootstrap required, opened a new log
I20260812 06:18:26.091045 20209 ts_tablet_manager.cc:1403] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Time spent bootstrapping tablet: real 0.009s	user 0.005s	sys 0.000s
I20260812 06:18:26.091867 20209 raft_consensus.cc:359] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b4ffb4e0895a4643b9dd9494c7b19081" member_type: VOTER last_known_addr { host: "127.19.114.129" port: 38243 } }
I20260812 06:18:26.092078 20209 raft_consensus.cc:385] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:26.092182 20209 raft_consensus.cc:740] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b4ffb4e0895a4643b9dd9494c7b19081, State: Initialized, Role: FOLLOWER
I20260812 06:18:26.092442 20209 consensus_queue.cc:260] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081 [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: "b4ffb4e0895a4643b9dd9494c7b19081" member_type: VOTER last_known_addr { host: "127.19.114.129" port: 38243 } }
I20260812 06:18:26.092625 20209 raft_consensus.cc:399] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:26.092724 20209 raft_consensus.cc:493] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:26.092833 20209 raft_consensus.cc:3060] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:26.094193 20209 raft_consensus.cc:515] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b4ffb4e0895a4643b9dd9494c7b19081" member_type: VOTER last_known_addr { host: "127.19.114.129" port: 38243 } }
I20260812 06:18:26.094408 20209 leader_election.cc:304] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081 [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: b4ffb4e0895a4643b9dd9494c7b19081; no voters: 
I20260812 06:18:26.094765 20209 leader_election.cc:290] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:26.094880 20213 raft_consensus.cc:2804] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:26.095191 20213 raft_consensus.cc:697] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081 [term 1 LEADER]: Becoming Leader. State: Replica: b4ffb4e0895a4643b9dd9494c7b19081, State: Running, Role: LEADER
I20260812 06:18:26.095314 20209 ts_tablet_manager.cc:1434] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Time spent starting tablet: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:18:26.095405 20213 consensus_queue.cc:237] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081 [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: "b4ffb4e0895a4643b9dd9494c7b19081" member_type: VOTER last_known_addr { host: "127.19.114.129" port: 38243 } }
I20260812 06:18:26.095606 20188 heartbeater.cc:499] Master 127.19.114.190:35107 was elected leader, sending a full tablet report...
I20260812 06:18:26.099421 19966 catalog_manager.cc:5719] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081 reported cstate change: term changed from 0 to 1, leader changed from <none> to b4ffb4e0895a4643b9dd9494c7b19081 (127.19.114.129). New cstate: current_term: 1 leader_uuid: "b4ffb4e0895a4643b9dd9494c7b19081" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b4ffb4e0895a4643b9dd9494c7b19081" member_type: VOTER last_known_addr { host: "127.19.114.129" port: 38243 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:26.197714 19914 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.086s	user 0.025s	sys 0.012s
I20260812 06:18:26.270637 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushMRSOp(e75716b83e11459abd3bc3597d1d500f): perf score=7.148690
I20260812 06:18:26.402208 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushMRSOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.131s	user 0.103s	sys 0.024s Metrics: {"bytes_written":8205078,"cfile_init":1,"compiler_manager_pool.queue_time_us":214,"delete_count":0,"dirs.queue_time_us":100,"dirs.run_cpu_time_us":287,"dirs.run_wall_time_us":992,"drs_written":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4,"lbm_write_time_us":26874,"lbm_writes_lt_1ms":367,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"thread_start_us":131,"threads_started":1,"update_count":1000}
I20260812 06:18:26.403695 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling LogGCOp(e75716b83e11459abd3bc3597d1d500f): free 8725963 bytes of WAL
I20260812 06:18:26.404117 20082 log_reader.cc:385] T e75716b83e11459abd3bc3597d1d500f: removed 1 log segments from log reader
I20260812 06:18:26.404211 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000001 (ops 1-6)
I20260812 06:18:26.407066 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: LogGCOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:26.407497 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling UndoDeltaBlockGCOp(e75716b83e11459abd3bc3597d1d500f): 4514099 bytes on disk
I20260812 06:18:26.408209 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: UndoDeltaBlockGCOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:18:26.408699 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:26.428048 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.019s	user 0.001s	sys 0.014s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6497,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:26.428663 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:26.445334 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.016s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6128,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.446066 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:26.596134 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.150s	user 0.107s	sys 0.037s Metrics: {"cfile_cache_miss":423,"cfile_cache_miss_bytes":20180212,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2065,"lbm_read_time_us":10819,"lbm_reads_lt_1ms":459,"lbm_write_time_us":26970,"lbm_writes_lt_1ms":433,"mutex_wait_us":436,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":14848,"thread_start_us":405,"threads_started":5,"update_count":1950}
I20260812 06:18:26.597081 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=7.149875
I20260812 06:18:26.636847 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.039s	user 0.017s	sys 0.020s Metrics: {"bytes_written":8615324,"delete_count":0,"lbm_write_time_us":16962,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:26.637532 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:26.652562 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5241,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:26.653429 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:26.773069 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.119s	user 0.087s	sys 0.031s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487927,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":746,"lbm_read_time_us":7647,"lbm_reads_lt_1ms":364,"lbm_write_time_us":22175,"lbm_writes_lt_1ms":343,"mutex_wait_us":404,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":21120,"update_count":1500}
I20260812 06:18:26.774000 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=10.126437
I20260812 06:18:26.816228 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.042s	user 0.025s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18765,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.816934 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:26.834141 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6832,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.834620 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:26.983819 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.149s	user 0.102s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":925,"lbm_read_time_us":9478,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24504,"lbm_writes_lt_1ms":443,"mutex_wait_us":76,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2000}
I20260812 06:18:26.984965 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=10.126437
I20260812 06:18:27.026939 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.042s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15877,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:27.027729 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:27.040603 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4748,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.041282 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:27.178489 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.137s	user 0.116s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2972,"lbm_read_time_us":10329,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25901,"lbm_writes_lt_1ms":443,"mutex_wait_us":1420,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2000}
I20260812 06:18:27.179190 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=10.126437
I20260812 06:18:27.221604 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.042s	user 0.033s	sys 0.005s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":17754,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:27.222438 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:27.235445 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4599,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.236207 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:27.364161 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.128s	user 0.091s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590350,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":399,"lbm_read_time_us":9982,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23939,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:27.364777 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=10.126437
I20260812 06:18:27.422389 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.057s	user 0.029s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17979,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:27.423177 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:27.435634 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4682,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.436188 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:27.600266 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.164s	user 0.111s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1224,"lbm_read_time_us":12254,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26420,"lbm_writes_lt_1ms":443,"mutex_wait_us":92,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:27.601044 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=10.126437
I20260812 06:18:27.644222 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.043s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18067,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:27.644807 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:27.658985 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.014s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4509,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.659565 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:27.802621 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.143s	user 0.103s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":421,"lbm_read_time_us":10461,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26494,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.803369 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=10.126437
I20260812 06:18:27.847478 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.044s	user 0.035s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18425,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":1500}
I20260812 06:18:27.848008 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushMRSOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:27.905920 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushMRSOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.058s	user 0.030s	sys 0.005s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":132,"dirs.run_cpu_time_us":381,"dirs.run_wall_time_us":1388,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1808,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:27.907050 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling LogGCOp(e75716b83e11459abd3bc3597d1d500f): free 115943167 bytes of WAL
I20260812 06:18:27.907519 20082 log_reader.cc:385] T e75716b83e11459abd3bc3597d1d500f: removed 11 log segments from log reader
I20260812 06:18:27.907634 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000002 (ops 7-11)
I20260812 06:18:27.907702 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000003 (ops 12-16)
I20260812 06:18:27.907761 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000004 (ops 17-21)
I20260812 06:18:27.907804 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000005 (ops 22-26)
I20260812 06:18:27.907843 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000006 (ops 27-31)
I20260812 06:18:27.907886 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000007 (ops 32-36)
I20260812 06:18:27.907939 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000008 (ops 37-41)
I20260812 06:18:27.907979 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000009 (ops 42-46)
I20260812 06:18:27.908012 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000010 (ops 47-51)
I20260812 06:18:27.908046 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000011 (ops 52-56)
I20260812 06:18:27.908087 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000012 (ops 57-61)
I20260812 06:18:27.939440 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: LogGCOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.032s	user 0.004s	sys 0.028s Metrics: {}
I20260812 06:18:27.940042 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=7.149875
I20260812 06:18:27.970587 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.030s	user 0.023s	sys 0.004s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":13151,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:27.971174 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling LogGCOp(e75716b83e11459abd3bc3597d1d500f): free 12017932 bytes of WAL
I20260812 06:18:27.971402 20082 log_reader.cc:385] T e75716b83e11459abd3bc3597d1d500f: removed 1 log segments from log reader
I20260812 06:18:27.971447 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000013 (ops 62-66)
I20260812 06:18:27.974567 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: LogGCOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:27.975245 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling UndoDeltaBlockGCOp(e75716b83e11459abd3bc3597d1d500f): 472 bytes on disk
I20260812 06:18:27.975739 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: UndoDeltaBlockGCOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:18:27.976274 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:27.992729 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5857,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:27.993332 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:28.174929 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.181s	user 0.151s	sys 0.027s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795282,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":989,"lbm_read_time_us":13140,"lbm_reads_lt_1ms":665,"lbm_write_time_us":35648,"lbm_writes_lt_1ms":643,"mutex_wait_us":88,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":128,"threads_started":1,"update_count":3000}
I20260812 06:18:28.175657 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=14.095187
I20260812 06:18:28.241035 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.065s	user 0.038s	sys 0.022s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":28231,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.241947 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:28.272274 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.030s	user 0.007s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6806,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.273082 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:28.286662 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4833,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.287395 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:28.482323 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.195s	user 0.142s	sys 0.049s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795287,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":377,"lbm_read_time_us":14853,"lbm_reads_lt_1ms":673,"lbm_write_time_us":40263,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:18:28.483067 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=14.095187
I20260812 06:18:28.544431 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.061s	user 0.015s	sys 0.044s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25918,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.545183 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:28.563046 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.018s	user 0.014s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6686,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.563706 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:28.741607 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.178s	user 0.100s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692757,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":329,"lbm_read_time_us":12795,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31238,"lbm_writes_lt_1ms":543,"mutex_wait_us":111,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:18:28.742460 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=14.095187
I20260812 06:18:28.811646 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.069s	user 0.038s	sys 0.023s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":27947,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.812655 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:28.972268 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.159s	user 0.108s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20590230,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":234,"lbm_read_time_us":13141,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24172,"lbm_writes_lt_1ms":443,"mutex_wait_us":64,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":51200,"update_count":2000}
I20260812 06:18:28.973467 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=14.095187
I20260812 06:18:29.034680 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.061s	user 0.029s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25841,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:29.035400 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:29.049767 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4771,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.050472 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:29.244479 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.194s	user 0.140s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":272,"lbm_read_time_us":12267,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32728,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22272,"update_count":2500}
I20260812 06:18:29.245348 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=14.095187
I20260812 06:18:29.309077 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.063s	user 0.031s	sys 0.024s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":25999,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:29.309687 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:29.322582 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4735,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.323156 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:29.485649 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.162s	user 0.120s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692761,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":810,"lbm_read_time_us":11435,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32821,"lbm_writes_lt_1ms":543,"mutex_wait_us":403,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24320,"update_count":2500}
I20260812 06:18:29.489421 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=10.126437
I20260812 06:18:29.537595 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.048s	user 0.021s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19454,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:29.538277 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:29.562048 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.024s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6273,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.562700 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushMRSOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:29.627451 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushMRSOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.065s	user 0.034s	sys 0.007s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":115,"dirs.run_cpu_time_us":274,"dirs.run_wall_time_us":1675,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2821,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:29.628325 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling LogGCOp(e75716b83e11459abd3bc3597d1d500f): free 121459489 bytes of WAL
I20260812 06:18:29.628647 20082 log_reader.cc:385] T e75716b83e11459abd3bc3597d1d500f: removed 12 log segments from log reader
I20260812 06:18:29.628734 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000014 (ops 67-71)
I20260812 06:18:29.628799 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000015 (ops 72-76)
I20260812 06:18:29.628862 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000016 (ops 77-81)
I20260812 06:18:29.628908 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000017 (ops 82-86)
I20260812 06:18:29.628949 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000018 (ops 87-91)
I20260812 06:18:29.628989 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000019 (ops 92-96)
I20260812 06:18:29.629029 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000020 (ops 97-101)
I20260812 06:18:29.629067 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000021 (ops 102-106)
I20260812 06:18:29.629105 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000022 (ops 107-111)
I20260812 06:18:29.629144 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000023 (ops 112-116)
I20260812 06:18:29.629184 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000024 (ops 117-121)
I20260812 06:18:29.629221 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000025 (ops 122-126)
I20260812 06:18:29.657815 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: LogGCOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:29.658507 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=6.157687
I20260812 06:18:29.683209 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.025s	user 0.005s	sys 0.019s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":10647,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:29.684052 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling LogGCOp(e75716b83e11459abd3bc3597d1d500f): free 11564883 bytes of WAL
I20260812 06:18:29.684474 20082 log_reader.cc:385] T e75716b83e11459abd3bc3597d1d500f: removed 1 log segments from log reader
I20260812 06:18:29.684566 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000026 (ops 127-130)
I20260812 06:18:29.688199 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: LogGCOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:29.688815 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling UndoDeltaBlockGCOp(e75716b83e11459abd3bc3597d1d500f): 493 bytes on disk
I20260812 06:18:29.689400 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: UndoDeltaBlockGCOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:18:29.690043 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:29.714011 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.024s	user 0.000s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7178,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.714747 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:29.968140 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.253s	user 0.156s	sys 0.086s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32897823,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":728,"lbm_read_time_us":17116,"lbm_reads_lt_1ms":766,"lbm_write_time_us":45138,"lbm_writes_lt_1ms":743,"mutex_wait_us":74,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1920,"thread_start_us":91,"threads_started":1,"update_count":3500}
I20260812 06:18:29.969007 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=18.063937
I20260812 06:18:30.048759 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.080s	user 0.038s	sys 0.039s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":35502,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:30.049464 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:30.061625 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4824,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.062469 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:30.283731 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.221s	user 0.150s	sys 0.071s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28795173,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":129,"lbm_read_time_us":15529,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37017,"lbm_writes_lt_1ms":643,"mutex_wait_us":31,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":3000}
I20260812 06:18:30.289263 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=14.095187
I20260812 06:18:30.349915 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.060s	user 0.033s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27253,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.350582 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:30.373739 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.023s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7007,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.374364 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:30.574309 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.200s	user 0.112s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":13882,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33900,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":28544,"update_count":2500}
I20260812 06:18:30.575166 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=14.095187
I20260812 06:18:30.640697 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.065s	user 0.038s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23196,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.641475 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:30.653777 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4859,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.654485 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:30.881096 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.226s	user 0.139s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692757,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":711,"lbm_read_time_us":16899,"lbm_reads_lt_1ms":572,"lbm_write_time_us":38209,"lbm_writes_lt_1ms":543,"mutex_wait_us":99,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:30.881835 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=14.095187
I20260812 06:18:30.955268 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.073s	user 0.038s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21603,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.956250 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:30.971172 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5997,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.971745 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:31.166079 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.194s	user 0.119s	sys 0.073s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":428,"lbm_read_time_us":16719,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33453,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:18:31.167054 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=10.126437
I20260812 06:18:31.202688 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.035s	user 0.017s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15272,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:31.203385 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:31.227665 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.024s	user 0.012s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6411,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.228497 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushMRSOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:31.286814 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushMRSOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.058s	user 0.038s	sys 0.001s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":279,"dirs.run_cpu_time_us":437,"dirs.run_wall_time_us":1768,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3280,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:31.287784 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=3.181125
I20260812 06:18:31.305207 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.017s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5337,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:31.305847 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling LogGCOp(e75716b83e11459abd3bc3597d1d500f): free 112239554 bytes of WAL
I20260812 06:18:31.306177 20082 log_reader.cc:385] T e75716b83e11459abd3bc3597d1d500f: removed 11 log segments from log reader
I20260812 06:18:31.306249 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000027 (ops 131-135)
I20260812 06:18:31.306294 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000028 (ops 136-140)
I20260812 06:18:31.306318 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000029 (ops 141-145)
I20260812 06:18:31.306340 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000030 (ops 146-150)
I20260812 06:18:31.306362 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000031 (ops 151-155)
I20260812 06:18:31.306385 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000032 (ops 156-160)
I20260812 06:18:31.306409 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000033 (ops 161-165)
I20260812 06:18:31.306435 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000034 (ops 166-170)
I20260812 06:18:31.306473 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000035 (ops 171-174)
I20260812 06:18:31.306495 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000036 (ops 175-179)
I20260812 06:18:31.306517 20082 log.cc:1079] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/e75716b83e11459abd3bc3597d1d500f/wal-000000037 (ops 180-184)
I20260812 06:18:31.335973 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: LogGCOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:31.336433 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:31.365103 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.028s	user 0.008s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6279,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:31.365844 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling UndoDeltaBlockGCOp(e75716b83e11459abd3bc3597d1d500f): 447 bytes on disk
I20260812 06:18:31.366376 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: UndoDeltaBlockGCOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:18:31.367054 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=2.188937
I20260812 06:18:31.381197 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5002,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.381771 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:31.649462 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.267s	user 0.177s	sys 0.087s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32897929,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":864,"lbm_read_time_us":19352,"lbm_reads_lt_1ms":775,"lbm_write_time_us":41532,"lbm_writes_lt_1ms":743,"mutex_wait_us":32,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13312,"thread_start_us":98,"threads_started":1,"update_count":3500}
I20260812 06:18:31.650292 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f): perf score=18.063937
I20260812 06:18:31.723477 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: FlushDeltaMemStoresOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.073s	user 0.053s	sys 0.019s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":32718,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:31.724151 20189 maintenance_manager.cc:419] P b4ffb4e0895a4643b9dd9494c7b19081: Scheduling MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f): perf score=1.000000
I20260812 06:18:31.747280 19914 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.549s	user 1.979s	sys 0.161s
I20260812 06:18:31.832679 19914 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.085s	user 0.003s	sys 0.000s
I20260812 06:18:31.833551 19914 tablet_server.cc:179] TabletServer@127.19.114.129:0 shutting down...
I20260812 06:18:31.890420 20082 maintenance_manager.cc:643] P b4ffb4e0895a4643b9dd9494c7b19081: MajorDeltaCompactionOp(e75716b83e11459abd3bc3597d1d500f) complete. Timing: real 0.166s	user 0.125s	sys 0.040s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24692645,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1411,"lbm_read_time_us":15946,"lbm_reads_lt_1ms":559,"lbm_write_time_us":27441,"lbm_writes_lt_1ms":543,"mutex_wait_us":377,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":40576,"update_count":2500}
I20260812 06:18:31.891314 19914 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:31.891822 19914 tablet_replica.cc:333] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081: stopping tablet replica
I20260812 06:18:31.892189 19914 raft_consensus.cc:2243] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:31.892565 19914 raft_consensus.cc:2272] T e75716b83e11459abd3bc3597d1d500f P b4ffb4e0895a4643b9dd9494c7b19081 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:31.913136 19914 tablet_server.cc:196] TabletServer@127.19.114.129:0 shutdown complete.
I20260812 06:18:31.939340 19914 master.cc:562] Master@127.19.114.190:35107 shutting down...
I20260812 06:18:31.943995 19914 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:31.944270 19914 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:31.944379 19914 tablet_replica.cc:333] T 00000000000000000000000000000000 P 249e84130d0d44b4bfcbde4bfbb64581: stopping tablet replica
I20260812 06:18:31.958144 19914 master.cc:584] Master@127.19.114.190:35107 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6267 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:32.080088 19914 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.114.190:44635
I20260812 06:18:32.080600 19914 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:32.083782 20251 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:32.083900 20250 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:32.083922 20256 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:32.084025 19914 server_base.cc:1061] running on GCE node
I20260812 06:18:32.084249 19914 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:32.084291 19914 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:32.084309 19914 hybrid_clock.cc:648] HybridClock initialized: now 1786515512084309 us; error 0 us; skew 500 ppm
I20260812 06:18:32.085261 19914 webserver.cc:533] Webserver started at http://127.19.114.190:38751/ using document root <none> and password file <none>
I20260812 06:18:32.085424 19914 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:32.085469 19914 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:32.085525 19914 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:32.085932 19914 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/master-0-root/instance:
uuid: "a92ad70e260e4b3395e26ee9f3c876c1"
format_stamp: "Formatted at 2026-08-12 06:18:32 on dist-test-slave-1nl6"
I20260812 06:18:32.087951 19914 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:32.089423 20270 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:32.089907 19914 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:32.090047 19914 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/master-0-root
uuid: "a92ad70e260e4b3395e26ee9f3c876c1"
format_stamp: "Formatted at 2026-08-12 06:18:32 on dist-test-slave-1nl6"
I20260812 06:18:32.090158 19914 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:32.101657 19914 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:32.102173 19914 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:32.107419 19914 rpc_server.cc:307] RPC server started. Bound to: 127.19.114.190:44635
I20260812 06:18:32.111115 20380 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.114.190:44635 every 8 connection(s)
I20260812 06:18:32.111908 20382 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:32.114718 20382 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1: Bootstrap starting.
I20260812 06:18:32.115922 20382 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:32.117656 20382 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1: No bootstrap required, opened a new log
I20260812 06:18:32.118199 20382 raft_consensus.cc:359] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a92ad70e260e4b3395e26ee9f3c876c1" member_type: VOTER }
I20260812 06:18:32.118350 20382 raft_consensus.cc:385] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:32.118396 20382 raft_consensus.cc:740] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a92ad70e260e4b3395e26ee9f3c876c1, State: Initialized, Role: FOLLOWER
I20260812 06:18:32.118633 20382 consensus_queue.cc:260] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [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: "a92ad70e260e4b3395e26ee9f3c876c1" member_type: VOTER }
I20260812 06:18:32.118743 20382 raft_consensus.cc:399] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:32.118817 20382 raft_consensus.cc:493] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:32.118880 20382 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:32.120302 20382 raft_consensus.cc:515] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a92ad70e260e4b3395e26ee9f3c876c1" member_type: VOTER }
I20260812 06:18:32.120622 20382 leader_election.cc:304] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [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: a92ad70e260e4b3395e26ee9f3c876c1; no voters: 
I20260812 06:18:32.120937 20382 leader_election.cc:290] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:32.121248 20389 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:32.121538 20389 raft_consensus.cc:697] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [term 1 LEADER]: Becoming Leader. State: Replica: a92ad70e260e4b3395e26ee9f3c876c1, State: Running, Role: LEADER
I20260812 06:18:32.121579 20382 sys_catalog.cc:565] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:32.121717 20389 consensus_queue.cc:237] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [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: "a92ad70e260e4b3395e26ee9f3c876c1" member_type: VOTER }
I20260812 06:18:32.122365 20396 sys_catalog.cc:455] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [sys.catalog]: SysCatalogTable state changed. Reason: New leader a92ad70e260e4b3395e26ee9f3c876c1. Latest consensus state: current_term: 1 leader_uuid: "a92ad70e260e4b3395e26ee9f3c876c1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a92ad70e260e4b3395e26ee9f3c876c1" member_type: VOTER } }
I20260812 06:18:32.122467 20396 sys_catalog.cc:458] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:32.122663 20393 sys_catalog.cc:455] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a92ad70e260e4b3395e26ee9f3c876c1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a92ad70e260e4b3395e26ee9f3c876c1" member_type: VOTER } }
I20260812 06:18:32.122848 20393 sys_catalog.cc:458] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:32.123100 20407 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:32.124003 20407 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:32.124332 19914 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:32.126327 20407 catalog_manager.cc:1383] Generated new cluster ID: b6a6d4800e1d40f7a410b1293ba72cce
I20260812 06:18:32.126396 20407 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:32.135788 20407 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:32.136564 20407 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:32.149017 20407 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1: Generated new TSK 0
I20260812 06:18:32.149279 20407 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:32.157143 19914 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:32.160012 20423 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:32.160135 20422 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:32.160138 20429 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:32.160234 19914 server_base.cc:1061] running on GCE node
I20260812 06:18:32.160681 19914 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:32.160871 19914 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:32.160920 19914 hybrid_clock.cc:648] HybridClock initialized: now 1786515512160920 us; error 0 us; skew 500 ppm
I20260812 06:18:32.162215 19914 webserver.cc:533] Webserver started at http://127.19.114.129:46417/ using document root <none> and password file <none>
I20260812 06:18:32.162460 19914 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:32.162515 19914 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:32.162633 19914 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:32.163187 19914 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/instance:
uuid: "7207cac5983747139e2049ea9b0c6310"
format_stamp: "Formatted at 2026-08-12 06:18:32 on dist-test-slave-1nl6"
I20260812 06:18:32.164983 19914 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:32.166401 20442 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:32.166996 19914 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:32.167165 19914 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root
uuid: "7207cac5983747139e2049ea9b0c6310"
format_stamp: "Formatted at 2026-08-12 06:18:32 on dist-test-slave-1nl6"
I20260812 06:18:32.167307 19914 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:32.172427 19914 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:32.172984 19914 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:32.173388 19914 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:32.173954 19914 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:32.174031 19914 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:32.174127 19914 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:32.174186 19914 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:32.179685 19914 rpc_server.cc:307] RPC server started. Bound to: 127.19.114.129:41293
I20260812 06:18:32.181212 20566 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.114.129:41293 every 8 connection(s)
I20260812 06:18:32.192806 20569 heartbeater.cc:344] Connected to a master server at 127.19.114.190:44635
I20260812 06:18:32.193029 20569 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:32.193364 20569 heartbeater.cc:507] Master 127.19.114.190:44635 requested a full tablet report, sending...
I20260812 06:18:32.194262 20299 ts_manager.cc:194] Registered new tserver with Master: 7207cac5983747139e2049ea9b0c6310 (127.19.114.129:41293)
I20260812 06:18:32.194339 19914 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013067492s
I20260812 06:18:32.195432 20299 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:59956
I20260812 06:18:32.204968 20299 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:59960:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:32.217324 20494 tablet_service.cc:1511] Processing CreateTablet for tablet 1b79aa65819e42e6b6ed25ede86c1028 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ad7657579d1642459e9dc7dd0cb67dc6]), partition=
I20260812 06:18:32.217715 20494 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1b79aa65819e42e6b6ed25ede86c1028. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:32.220468 20592 tablet_bootstrap.cc:492] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Bootstrap starting.
I20260812 06:18:32.221508 20592 tablet_bootstrap.cc:654] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:32.223186 20592 tablet_bootstrap.cc:492] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: No bootstrap required, opened a new log
I20260812 06:18:32.223342 20592 ts_tablet_manager.cc:1403] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:32.223879 20592 raft_consensus.cc:359] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7207cac5983747139e2049ea9b0c6310" member_type: VOTER last_known_addr { host: "127.19.114.129" port: 41293 } }
I20260812 06:18:32.224017 20592 raft_consensus.cc:385] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:32.224067 20592 raft_consensus.cc:740] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7207cac5983747139e2049ea9b0c6310, State: Initialized, Role: FOLLOWER
I20260812 06:18:32.224247 20592 consensus_queue.cc:260] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310 [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: "7207cac5983747139e2049ea9b0c6310" member_type: VOTER last_known_addr { host: "127.19.114.129" port: 41293 } }
I20260812 06:18:32.224355 20592 raft_consensus.cc:399] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:32.224402 20592 raft_consensus.cc:493] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:32.224457 20592 raft_consensus.cc:3060] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:32.225322 20592 raft_consensus.cc:515] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7207cac5983747139e2049ea9b0c6310" member_type: VOTER last_known_addr { host: "127.19.114.129" port: 41293 } }
I20260812 06:18:32.225515 20592 leader_election.cc:304] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310 [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: 7207cac5983747139e2049ea9b0c6310; no voters: 
I20260812 06:18:32.225792 20592 leader_election.cc:290] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:32.225920 20594 raft_consensus.cc:2804] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:32.226293 20594 raft_consensus.cc:697] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310 [term 1 LEADER]: Becoming Leader. State: Replica: 7207cac5983747139e2049ea9b0c6310, State: Running, Role: LEADER
I20260812 06:18:32.226508 20592 ts_tablet_manager.cc:1434] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:32.226562 20594 consensus_queue.cc:237] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310 [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: "7207cac5983747139e2049ea9b0c6310" member_type: VOTER last_known_addr { host: "127.19.114.129" port: 41293 } }
I20260812 06:18:32.226542 20569 heartbeater.cc:499] Master 127.19.114.190:44635 was elected leader, sending a full tablet report...
I20260812 06:18:32.228670 20299 catalog_manager.cc:5719] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310 reported cstate change: term changed from 0 to 1, leader changed from <none> to 7207cac5983747139e2049ea9b0c6310 (127.19.114.129). New cstate: current_term: 1 leader_uuid: "7207cac5983747139e2049ea9b0c6310" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7207cac5983747139e2049ea9b0c6310" member_type: VOTER last_known_addr { host: "127.19.114.129" port: 41293 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:32.299419 19914 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.064s	user 0.025s	sys 0.000s
I20260812 06:18:32.432107 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushMRSOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=15.086190
I20260812 06:18:32.575829 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushMRSOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.143s	user 0.099s	sys 0.036s Metrics: {"bytes_written":8205079,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":124,"dirs.run_cpu_time_us":284,"dirs.run_wall_time_us":1108,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":32531,"lbm_writes_lt_1ms":557,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"update_count":1000}
I20260812 06:18:32.577260 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling LogGCOp(1b79aa65819e42e6b6ed25ede86c1028): free 11976772 bytes of WAL
I20260812 06:18:32.577674 20455 log_reader.cc:385] T 1b79aa65819e42e6b6ed25ede86c1028: removed 1 log segments from log reader
I20260812 06:18:32.577756 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000001 (ops 1-6)
I20260812 06:18:32.581528 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: LogGCOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:32.582060 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:32.607684 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.025s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7353,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.608405 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling UndoDeltaBlockGCOp(1b79aa65819e42e6b6ed25ede86c1028): 12308960 bytes on disk
I20260812 06:18:32.608902 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: UndoDeltaBlockGCOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:18:32.609367 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:32.746867 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.137s	user 0.108s	sys 0.028s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528901,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":854,"lbm_read_time_us":12745,"lbm_reads_lt_1ms":360,"lbm_write_time_us":20953,"lbm_writes_lt_1ms":343,"mutex_wait_us":24,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":5120,"thread_start_us":403,"threads_started":5,"update_count":1500}
I20260812 06:18:32.747676 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=10.126437
I20260812 06:18:32.798568 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.051s	user 0.014s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18191,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:32.799175 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:32.812870 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4440,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.813719 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:32.961105 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.147s	user 0.111s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":295,"lbm_read_time_us":10604,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25955,"lbm_writes_lt_1ms":443,"mutex_wait_us":148,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:18:32.961876 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=10.126437
I20260812 06:18:33.021335 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.059s	user 0.035s	sys 0.009s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":20694,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.022017 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:33.034495 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4722,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.035120 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:33.199443 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.164s	user 0.119s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":194,"lbm_read_time_us":12630,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27464,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:18:33.200160 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=10.126437
I20260812 06:18:33.247278 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.047s	user 0.032s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19921,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.247913 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:33.260637 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.013s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4724,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.261157 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:33.411316 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.150s	user 0.111s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":273,"lbm_read_time_us":10347,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25936,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":32768,"update_count":2000}
I20260812 06:18:33.412014 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=10.126437
I20260812 06:18:33.465648 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.053s	user 0.019s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16698,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.466377 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:33.479795 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4908,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.480577 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:33.623963 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.143s	user 0.107s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":273,"lbm_read_time_us":10089,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28395,"lbm_writes_lt_1ms":443,"mutex_wait_us":55,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:18:33.624819 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=10.126437
I20260812 06:18:33.673899 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.049s	user 0.033s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20057,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.674525 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:33.687469 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.013s	user 0.009s	sys 0.003s 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:18:33.688123 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:33.837990 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.150s	user 0.105s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1432,"lbm_read_time_us":10958,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30584,"lbm_writes_lt_1ms":443,"mutex_wait_us":449,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2000}
I20260812 06:18:33.838622 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=10.126437
I20260812 06:18:33.894625 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.056s	user 0.027s	sys 0.021s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17525,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.895318 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:33.907151 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4644,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.907661 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:34.081496 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.174s	user 0.121s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1460,"lbm_read_time_us":13135,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27298,"lbm_writes_lt_1ms":443,"mutex_wait_us":302,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2000}
I20260812 06:18:34.082185 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=10.126437
I20260812 06:18:34.132292 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.050s	user 0.035s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15127,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:34.133067 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:34.151583 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.018s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7368,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.152118 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushMRSOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:34.188841 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushMRSOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.036s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":110,"dirs.run_cpu_time_us":294,"dirs.run_wall_time_us":1811,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1788,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:34.189608 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling LogGCOp(1b79aa65819e42e6b6ed25ede86c1028): free 129773549 bytes of WAL
I20260812 06:18:34.189872 20455 log_reader.cc:385] T 1b79aa65819e42e6b6ed25ede86c1028: removed 13 log segments from log reader
I20260812 06:18:34.189947 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000002 (ops 7-11)
I20260812 06:18:34.190004 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000003 (ops 12-16)
I20260812 06:18:34.190074 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000004 (ops 17-21)
I20260812 06:18:34.190119 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000005 (ops 22-26)
I20260812 06:18:34.190156 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000006 (ops 27-31)
I20260812 06:18:34.190196 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000007 (ops 32-36)
I20260812 06:18:34.190233 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000008 (ops 37-40)
I20260812 06:18:34.190270 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000009 (ops 41-45)
I20260812 06:18:34.190308 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000010 (ops 46-50)
I20260812 06:18:34.190352 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000011 (ops 51-55)
I20260812 06:18:34.190387 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000012 (ops 56-60)
I20260812 06:18:34.190426 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000013 (ops 61-65)
I20260812 06:18:34.190464 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000014 (ops 66-70)
I20260812 06:18:34.224428 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: LogGCOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.035s	user 0.000s	sys 0.034s Metrics: {}
I20260812 06:18:34.224903 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=6.157687
I20260812 06:18:34.256995 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.032s	user 0.022s	sys 0.005s Metrics: {"bytes_written":8205080,"delete_count":0,"lbm_write_time_us":11918,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:34.257512 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling UndoDeltaBlockGCOp(1b79aa65819e42e6b6ed25ede86c1028): 482 bytes on disk
I20260812 06:18:34.257967 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: UndoDeltaBlockGCOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4}
I20260812 06:18:34.258464 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:34.495528 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.237s	user 0.151s	sys 0.083s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836258,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":705,"lbm_read_time_us":17533,"lbm_reads_lt_1ms":665,"lbm_write_time_us":35619,"lbm_writes_lt_1ms":643,"mutex_wait_us":91,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":31232,"thread_start_us":95,"threads_started":1,"update_count":3000}
I20260812 06:18:34.496416 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=14.095187
I20260812 06:18:34.564296 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.067s	user 0.034s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22906,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.564883 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:34.578737 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5426,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.579389 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:34.787235 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.208s	user 0.151s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3298,"lbm_read_time_us":14273,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32534,"lbm_writes_lt_1ms":543,"mutex_wait_us":2972,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":41344,"update_count":2500}
I20260812 06:18:34.788076 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=14.095187
I20260812 06:18:34.844110 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.056s	user 0.036s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23206,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.845003 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:34.858512 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4139,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.859134 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:35.078831 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.219s	user 0.122s	sys 0.087s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":692,"lbm_read_time_us":14651,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33634,"lbm_writes_lt_1ms":543,"mutex_wait_us":363,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":324224,"update_count":2500}
I20260812 06:18:35.079557 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=14.095187
I20260812 06:18:35.139909 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.060s	user 0.020s	sys 0.039s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26628,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:35.140558 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:35.160876 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.020s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6226,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.161446 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:35.334575 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.173s	user 0.112s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":322,"lbm_read_time_us":10518,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32361,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":195072,"update_count":2500}
I20260812 06:18:35.335386 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=14.095187
I20260812 06:18:35.387884 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.052s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23116,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:35.388806 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:35.407369 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.018s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7058,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.407972 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:35.570269 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.162s	user 0.135s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":415,"lbm_read_time_us":13110,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33410,"lbm_writes_lt_1ms":543,"mutex_wait_us":91,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:18:35.570983 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=11.118625
I20260812 06:18:35.614123 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.043s	user 0.035s	sys 0.005s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":19325,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:35.614720 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:35.627310 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4591,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:35.628028 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:35.769925 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.142s	user 0.112s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631305,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":563,"lbm_read_time_us":9531,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26714,"lbm_writes_lt_1ms":443,"mutex_wait_us":75,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:18:35.771117 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=10.126437
I20260812 06:18:35.824326 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.052s	user 0.034s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":25613,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:35.824959 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:35.837077 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4293,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.837864 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushMRSOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:35.872568 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushMRSOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.034s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":303,"dirs.run_wall_time_us":1524,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1740,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:35.873309 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling LogGCOp(1b79aa65819e42e6b6ed25ede86c1028): free 124710306 bytes of WAL
I20260812 06:18:35.873576 20455 log_reader.cc:385] T 1b79aa65819e42e6b6ed25ede86c1028: removed 12 log segments from log reader
I20260812 06:18:35.873642 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000015 (ops 71-75)
I20260812 06:18:35.873675 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000016 (ops 76-80)
I20260812 06:18:35.873725 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000017 (ops 81-85)
I20260812 06:18:35.873770 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000018 (ops 86-90)
I20260812 06:18:35.873828 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000019 (ops 91-95)
I20260812 06:18:35.873875 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000020 (ops 96-100)
I20260812 06:18:35.873905 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000021 (ops 101-105)
I20260812 06:18:35.873948 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000022 (ops 106-110)
I20260812 06:18:35.873986 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000023 (ops 111-115)
I20260812 06:18:35.874027 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000024 (ops 116-120)
I20260812 06:18:35.874068 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000025 (ops 121-125)
I20260812 06:18:35.874109 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000026 (ops 126-130)
I20260812 06:18:35.906232 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: LogGCOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.033s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:35.906781 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=4.173312
I20260812 06:18:35.925554 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.019s	user 0.015s	sys 0.001s Metrics: {"bytes_written":6235918,"delete_count":0,"lbm_write_time_us":7554,"lbm_writes_lt_1ms":155,"reinsert_count":0,"update_count":760}
I20260812 06:18:35.926282 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:35.937713 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":1969352,"delete_count":0,"lbm_write_time_us":3859,"lbm_writes_lt_1ms":51,"reinsert_count":0,"update_count":240}
I20260812 06:18:35.938649 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:36.130432 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.191s	user 0.136s	sys 0.055s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836322,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1135,"lbm_read_time_us":14779,"lbm_reads_lt_1ms":666,"lbm_write_time_us":38489,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":235,"threads_started":1,"update_count":3000}
I20260812 06:18:36.131330 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=14.095187
I20260812 06:18:36.198208 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.067s	user 0.044s	sys 0.018s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":30198,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:36.199131 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:36.219573 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.020s	user 0.015s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8178,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.220198 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling UndoDeltaBlockGCOp(1b79aa65819e42e6b6ed25ede86c1028): 473 bytes on disk
I20260812 06:18:36.220880 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: UndoDeltaBlockGCOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:18:36.221658 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:36.394090 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.172s	user 0.096s	sys 0.071s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1084,"lbm_read_time_us":12968,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33060,"lbm_writes_lt_1ms":543,"mutex_wait_us":311,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2500}
I20260812 06:18:36.395273 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=13.103000
I20260812 06:18:36.464466 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.069s	user 0.043s	sys 0.008s Metrics: {"bytes_written":15384296,"delete_count":0,"lbm_write_time_us":24512,"lbm_writes_lt_1ms":378,"reinsert_count":0,"update_count":1875}
I20260812 06:18:36.465039 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=3.181125
I20260812 06:18:36.479754 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":5128269,"delete_count":0,"lbm_write_time_us":5730,"lbm_writes_lt_1ms":128,"reinsert_count":0,"update_count":625}
I20260812 06:18:36.480351 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:36.663380 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.183s	user 0.133s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733728,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":481,"lbm_read_time_us":14572,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30733,"lbm_writes_lt_1ms":543,"mutex_wait_us":69,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25728,"update_count":2500}
I20260812 06:18:36.664036 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=11.118625
I20260812 06:18:36.713547 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.049s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":19412,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:36.714239 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:36.745087 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.031s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7209,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.745635 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:36.756716 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4236,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:36.757268 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:36.947783 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.190s	user 0.113s	sys 0.072s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733836,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":3040,"lbm_read_time_us":14201,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30661,"lbm_writes_lt_1ms":543,"mutex_wait_us":505,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:18:36.948446 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=14.095187
I20260812 06:18:37.009162 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.060s	user 0.024s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22990,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.009822 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:37.023490 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4827,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.024130 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:37.220438 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.196s	user 0.120s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1144,"lbm_read_time_us":16795,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30700,"lbm_writes_lt_1ms":543,"mutex_wait_us":156,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27904,"update_count":2500}
I20260812 06:18:37.221442 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=14.095187
I20260812 06:18:37.292630 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.071s	user 0.035s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23827,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.293272 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:37.305234 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4748,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.305855 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:37.511273 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.205s	user 0.117s	sys 0.081s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1097,"lbm_read_time_us":16714,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30957,"lbm_writes_lt_1ms":543,"mutex_wait_us":344,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:18:37.511950 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=11.118625
I20260812 06:18:37.551909 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.040s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17398,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:37.553268 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:37.574992 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.021s	user 0.007s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6424,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:37.575601 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushMRSOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:37.636803 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushMRSOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.061s	user 0.037s	sys 0.008s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":150,"dirs.run_cpu_time_us":443,"dirs.run_wall_time_us":1742,"drs_written":1,"lbm_read_time_us":109,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2849,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:37.637588 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling UndoDeltaBlockGCOp(1b79aa65819e42e6b6ed25ede86c1028): 492 bytes on disk
I20260812 06:18:37.638532 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: UndoDeltaBlockGCOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":221,"lbm_reads_lt_1ms":4}
I20260812 06:18:37.639468 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=3.181125
I20260812 06:18:37.661361 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.022s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4512904,"delete_count":0,"lbm_write_time_us":7961,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:37.661989 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling LogGCOp(1b79aa65819e42e6b6ed25ede86c1028): free 132118544 bytes of WAL
I20260812 06:18:37.662242 20455 log_reader.cc:385] T 1b79aa65819e42e6b6ed25ede86c1028: removed 13 log segments from log reader
I20260812 06:18:37.662317 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000027 (ops 131-134)
I20260812 06:18:37.662381 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000028 (ops 135-139)
I20260812 06:18:37.662448 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000029 (ops 140-144)
I20260812 06:18:37.662493 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000030 (ops 145-149)
I20260812 06:18:37.662530 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000031 (ops 150-154)
I20260812 06:18:37.662570 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000032 (ops 155-158)
I20260812 06:18:37.662609 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000033 (ops 159-163)
I20260812 06:18:37.662647 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000034 (ops 164-168)
I20260812 06:18:37.662685 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000035 (ops 169-173)
I20260812 06:18:37.662725 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000036 (ops 174-178)
I20260812 06:18:37.662765 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000037 (ops 179-182)
I20260812 06:18:37.662803 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000038 (ops 183-187)
I20260812 06:18:37.662839 20455 log.cc:1079] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: Deleting log segment in path: /tmp/dist-test-task0Y_KdW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505784357-19914-0/minicluster-data/ts-0-root/wals/1b79aa65819e42e6b6ed25ede86c1028/wal-000000039 (ops 188-192)
I20260812 06:18:37.697197 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: LogGCOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.035s	user 0.002s	sys 0.031s Metrics: {}
I20260812 06:18:37.697819 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:37.712116 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.014s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5800,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.712759 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=2.188937
I20260812 06:18:37.724367 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: FlushDeltaMemStoresOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4380,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:37.724967 20571 maintenance_manager.cc:419] P 7207cac5983747139e2049ea9b0c6310: Scheduling MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028): perf score=1.000000
I20260812 06:18:37.841228 19914 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.542s	user 1.989s	sys 0.171s
I20260812 06:18:37.955097 19914 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.113s	user 0.004s	sys 0.000s
I20260812 06:18:37.955756 19914 tablet_server.cc:179] TabletServer@127.19.114.129:0 shutting down...
I20260812 06:18:37.964579 20455 maintenance_manager.cc:643] P 7207cac5983747139e2049ea9b0c6310: MajorDeltaCompactionOp(1b79aa65819e42e6b6ed25ede86c1028) complete. Timing: real 0.239s	user 0.145s	sys 0.094s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32938888,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":738,"lbm_read_time_us":19130,"lbm_reads_lt_1ms":771,"lbm_write_time_us":37743,"lbm_writes_lt_1ms":743,"mutex_wait_us":233,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":46080,"thread_start_us":89,"threads_started":1,"update_count":3500}
I20260812 06:18:37.965987 19914 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:37.966410 19914 tablet_replica.cc:333] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310: stopping tablet replica
I20260812 06:18:37.966575 19914 raft_consensus.cc:2243] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:37.982005 19914 raft_consensus.cc:2272] T 1b79aa65819e42e6b6ed25ede86c1028 P 7207cac5983747139e2049ea9b0c6310 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:37.991139 19914 tablet_server.cc:196] TabletServer@127.19.114.129:0 shutdown complete.
I20260812 06:18:38.028934 19914 master.cc:562] Master@127.19.114.190:44635 shutting down...
I20260812 06:18:38.033499 19914 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:38.033743 19914 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:38.033850 19914 tablet_replica.cc:333] T 00000000000000000000000000000000 P a92ad70e260e4b3395e26ee9f3c876c1: stopping tablet replica
I20260812 06:18:38.047335 19914 master.cc:584] Master@127.19.114.190:44635 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6079 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12348 ms total)

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