[==========] 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:15.073652 19095 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.18.165.254:40211
I20260812 06:18:15.074641 19095 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:15.075232 19095 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:15.082124 19100 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:15.082221 19095 server_base.cc:1061] running on GCE node
W20260812 06:18:15.082144 19107 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:15.082433 19103 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:15.082901 19095 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:15.083012 19095 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:15.083057 19095 hybrid_clock.cc:648] HybridClock initialized: now 1786515495083055 us; error 0 us; skew 500 ppm
I20260812 06:18:15.084935 19095 webserver.cc:533] Webserver started at http://127.18.165.254:44179/ using document root <none> and password file <none>
I20260812 06:18:15.085464 19095 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:15.085556 19095 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:15.085819 19095 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:15.087473 19095 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/master-0-root/instance:
uuid: "996ae6bfc6c6402ba925e260079d94aa"
format_stamp: "Formatted at 2026-08-12 06:18:15 on dist-test-slave-x4qh"
I20260812 06:18:15.090780 19095 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:15.092790 19121 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:15.093720 19095 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:15.093837 19095 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/master-0-root
uuid: "996ae6bfc6c6402ba925e260079d94aa"
format_stamp: "Formatted at 2026-08-12 06:18:15 on dist-test-slave-x4qh"
I20260812 06:18:15.093932 19095 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-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:15.106009 19095 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:15.106586 19095 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:15.106755 19095 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:15.114336 19204 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.165.254:40211 every 8 connection(s)
I20260812 06:18:15.114346 19095 rpc_server.cc:307] RPC server started. Bound to: 127.18.165.254:40211
I20260812 06:18:15.116551 19208 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:15.121690 19208 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa: Bootstrap starting.
I20260812 06:18:15.123926 19208 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:15.124799 19208 log.cc:826] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:15.126380 19208 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa: No bootstrap required, opened a new log
I20260812 06:18:15.129060 19208 raft_consensus.cc:359] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "996ae6bfc6c6402ba925e260079d94aa" member_type: VOTER }
I20260812 06:18:15.129210 19208 raft_consensus.cc:385] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:15.129287 19208 raft_consensus.cc:740] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 996ae6bfc6c6402ba925e260079d94aa, State: Initialized, Role: FOLLOWER
I20260812 06:18:15.129848 19208 consensus_queue.cc:260] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [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: "996ae6bfc6c6402ba925e260079d94aa" member_type: VOTER }
I20260812 06:18:15.130000 19208 raft_consensus.cc:399] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:15.130074 19208 raft_consensus.cc:493] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:15.130235 19208 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:15.130976 19208 raft_consensus.cc:515] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "996ae6bfc6c6402ba925e260079d94aa" member_type: VOTER }
I20260812 06:18:15.131407 19208 leader_election.cc:304] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [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: 996ae6bfc6c6402ba925e260079d94aa; no voters: 
I20260812 06:18:15.131703 19208 leader_election.cc:290] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:15.131870 19212 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:15.132107 19212 raft_consensus.cc:697] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [term 1 LEADER]: Becoming Leader. State: Replica: 996ae6bfc6c6402ba925e260079d94aa, State: Running, Role: LEADER
I20260812 06:18:15.132522 19212 consensus_queue.cc:237] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [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: "996ae6bfc6c6402ba925e260079d94aa" member_type: VOTER }
I20260812 06:18:15.132668 19208 sys_catalog.cc:565] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:15.134224 19222 sys_catalog.cc:455] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [sys.catalog]: SysCatalogTable state changed. Reason: New leader 996ae6bfc6c6402ba925e260079d94aa. Latest consensus state: current_term: 1 leader_uuid: "996ae6bfc6c6402ba925e260079d94aa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "996ae6bfc6c6402ba925e260079d94aa" member_type: VOTER } }
I20260812 06:18:15.134338 19222 sys_catalog.cc:458] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:15.134658 19217 sys_catalog.cc:455] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "996ae6bfc6c6402ba925e260079d94aa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "996ae6bfc6c6402ba925e260079d94aa" member_type: VOTER } }
I20260812 06:18:15.134743 19217 sys_catalog.cc:458] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:15.134965 19095 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:18:15.136826 19249 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:15.136888 19249 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:15.136961 19240 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:15.137647 19240 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:15.142020 19240 catalog_manager.cc:1383] Generated new cluster ID: 89246c72339a4f7981464717d998ebfe
I20260812 06:18:15.142081 19240 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:15.151815 19240 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:15.152575 19240 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:15.160033 19240 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa: Generated new TSK 0
I20260812 06:18:15.160562 19240 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:15.167600 19095 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:15.170501 19253 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:15.170533 19257 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:15.170693 19255 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:15.171028 19095 server_base.cc:1061] running on GCE node
I20260812 06:18:15.171224 19095 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:15.171271 19095 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:15.171294 19095 hybrid_clock.cc:648] HybridClock initialized: now 1786515495171294 us; error 0 us; skew 500 ppm
I20260812 06:18:15.172245 19095 webserver.cc:533] Webserver started at http://127.18.165.193:37667/ using document root <none> and password file <none>
I20260812 06:18:15.172411 19095 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:15.172472 19095 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:15.172546 19095 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:15.172981 19095 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/instance:
uuid: "7ebc0a19a6424f91bb55e005510fa66c"
format_stamp: "Formatted at 2026-08-12 06:18:15 on dist-test-slave-x4qh"
I20260812 06:18:15.174762 19095 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:15.175876 19262 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:15.176127 19095 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:18:15.176194 19095 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root
uuid: "7ebc0a19a6424f91bb55e005510fa66c"
format_stamp: "Formatted at 2026-08-12 06:18:15 on dist-test-slave-x4qh"
I20260812 06:18:15.176285 19095 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-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:15.195849 19095 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:15.196276 19095 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:15.196722 19095 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:15.197577 19095 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:15.197629 19095 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:15.197724 19095 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:15.197767 19095 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:15.204684 19095 rpc_server.cc:307] RPC server started. Bound to: 127.18.165.193:40595
I20260812 06:18:15.204730 19379 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.165.193:40595 every 8 connection(s)
I20260812 06:18:15.218897 19382 heartbeater.cc:344] Connected to a master server at 127.18.165.254:40211
I20260812 06:18:15.219149 19382 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:15.219638 19382 heartbeater.cc:507] Master 127.18.165.254:40211 requested a full tablet report, sending...
I20260812 06:18:15.221112 19150 ts_manager.cc:194] Registered new tserver with Master: 7ebc0a19a6424f91bb55e005510fa66c (127.18.165.193:40595)
I20260812 06:18:15.221225 19095 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015926133s
I20260812 06:18:15.222638 19150 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50668
I20260812 06:18:15.231141 19150 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50672:
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:15.244932 19309 tablet_service.cc:1511] Processing CreateTablet for tablet 23fedd2594d0499ba0580497b34ed684 (DEFAULT_TABLE table=heavy-update-compaction-test [id=b6d2dcdef479441998c52eff51e035c1]), partition=
I20260812 06:18:15.245409 19309 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 23fedd2594d0499ba0580497b34ed684. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:15.247543 19396 tablet_bootstrap.cc:492] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Bootstrap starting.
I20260812 06:18:15.248519 19396 tablet_bootstrap.cc:654] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:15.249675 19396 tablet_bootstrap.cc:492] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: No bootstrap required, opened a new log
I20260812 06:18:15.249786 19396 ts_tablet_manager.cc:1403] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:15.250154 19396 raft_consensus.cc:359] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ebc0a19a6424f91bb55e005510fa66c" member_type: VOTER last_known_addr { host: "127.18.165.193" port: 40595 } }
I20260812 06:18:15.250265 19396 raft_consensus.cc:385] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:15.250327 19396 raft_consensus.cc:740] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7ebc0a19a6424f91bb55e005510fa66c, State: Initialized, Role: FOLLOWER
I20260812 06:18:15.250481 19396 consensus_queue.cc:260] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c [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: "7ebc0a19a6424f91bb55e005510fa66c" member_type: VOTER last_known_addr { host: "127.18.165.193" port: 40595 } }
I20260812 06:18:15.250571 19396 raft_consensus.cc:399] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:15.250614 19396 raft_consensus.cc:493] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:15.250667 19396 raft_consensus.cc:3060] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:15.251334 19396 raft_consensus.cc:515] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ebc0a19a6424f91bb55e005510fa66c" member_type: VOTER last_known_addr { host: "127.18.165.193" port: 40595 } }
I20260812 06:18:15.251526 19396 leader_election.cc:304] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c [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: 7ebc0a19a6424f91bb55e005510fa66c; no voters: 
I20260812 06:18:15.251761 19396 leader_election.cc:290] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:15.251861 19400 raft_consensus.cc:2804] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:15.252044 19400 raft_consensus.cc:697] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c [term 1 LEADER]: Becoming Leader. State: Replica: 7ebc0a19a6424f91bb55e005510fa66c, State: Running, Role: LEADER
I20260812 06:18:15.252121 19396 ts_tablet_manager.cc:1434] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:15.252542 19382 heartbeater.cc:499] Master 127.18.165.254:40211 was elected leader, sending a full tablet report...
I20260812 06:18:15.252240 19400 consensus_queue.cc:237] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c [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: "7ebc0a19a6424f91bb55e005510fa66c" member_type: VOTER last_known_addr { host: "127.18.165.193" port: 40595 } }
I20260812 06:18:15.255503 19150 catalog_manager.cc:5719] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c reported cstate change: term changed from 0 to 1, leader changed from <none> to 7ebc0a19a6424f91bb55e005510fa66c (127.18.165.193). New cstate: current_term: 1 leader_uuid: "7ebc0a19a6424f91bb55e005510fa66c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ebc0a19a6424f91bb55e005510fa66c" member_type: VOTER last_known_addr { host: "127.18.165.193" port: 40595 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:15.332036 19095 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.066s	user 0.028s	sys 0.008s
I20260812 06:18:15.455749 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushMRSOp(23fedd2594d0499ba0580497b34ed684): perf score=15.086190
I20260812 06:18:15.620209 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushMRSOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.164s	user 0.129s	sys 0.032s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":297,"delete_count":0,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":951,"drs_written":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41741,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":666,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":301440,"thread_start_us":125,"threads_started":1,"update_count":1500}
I20260812 06:18:15.621219 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling LogGCOp(23fedd2594d0499ba0580497b34ed684): free 20743880 bytes of WAL
I20260812 06:18:15.621572 19269 log_reader.cc:385] T 23fedd2594d0499ba0580497b34ed684: removed 2 log segments from log reader
I20260812 06:18:15.621651 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000001 (ops 1-6)
I20260812 06:18:15.621747 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000002 (ops 7-11)
I20260812 06:18:15.627997 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: LogGCOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.007s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:18:15.628470 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:15.655830 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.027s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4833,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:15.656287 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:15.666505 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3979,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.666958 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:15.820688 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.154s	user 0.124s	sys 0.028s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364554,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":466,"lbm_read_time_us":12097,"lbm_reads_lt_1ms":563,"lbm_write_time_us":28681,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":290,"threads_started":5,"update_count":2450}
I20260812 06:18:15.821221 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling UndoDeltaBlockGCOp(23fedd2594d0499ba0580497b34ed684): 12719217 bytes on disk
I20260812 06:18:15.821682 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: UndoDeltaBlockGCOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:18:15.822099 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=10.126437
I20260812 06:18:15.872769 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.051s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16847,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:15.873283 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:15.884698 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4067,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.885211 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:16.016443 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.131s	user 0.098s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":8063,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27110,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2000}
I20260812 06:18:16.016945 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=10.126437
I20260812 06:18:16.061561 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.044s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15783,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:16.062018 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:16.072783 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4107,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.073407 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:16.191988 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.118s	user 0.103s	sys 0.014s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1061,"lbm_read_time_us":8442,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23215,"lbm_writes_lt_1ms":443,"mutex_wait_us":390,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21376,"update_count":2000}
I20260812 06:18:16.192584 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=10.126437
I20260812 06:18:16.235028 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.042s	user 0.015s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14793,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:16.235642 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:16.246466 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4257,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.246909 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:16.397123 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.150s	user 0.094s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":675,"lbm_read_time_us":11208,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24405,"lbm_writes_lt_1ms":443,"mutex_wait_us":296,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:18:16.397761 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=10.126437
I20260812 06:18:16.437707 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.040s	user 0.031s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15043,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:16.438163 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:16.448520 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4039,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.449203 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:16.579963 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.131s	user 0.099s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":748,"lbm_read_time_us":9494,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27476,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:18:16.580664 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=10.126437
I20260812 06:18:16.625356 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.045s	user 0.021s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17378,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:16.625840 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:16.637519 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4220,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.637967 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:16.768401 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.130s	user 0.101s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":235,"lbm_read_time_us":9174,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27365,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.769047 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=10.126437
I20260812 06:18:16.817644 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.048s	user 0.028s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14865,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:16.818152 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:16.829231 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4396,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.829716 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushMRSOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:16.861131 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushMRSOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.031s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1426,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1399,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:16.861928 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling UndoDeltaBlockGCOp(23fedd2594d0499ba0580497b34ed684): 448 bytes on disk
I20260812 06:18:16.862320 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: UndoDeltaBlockGCOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:16.862747 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:17.001454 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.139s	user 0.113s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":284,"lbm_read_time_us":9328,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22868,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:17.002149 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling LogGCOp(23fedd2594d0499ba0580497b34ed684): free 115943178 bytes of WAL
I20260812 06:18:17.002411 19269 log_reader.cc:385] T 23fedd2594d0499ba0580497b34ed684: removed 11 log segments from log reader
I20260812 06:18:17.002467 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000003 (ops 12-16)
I20260812 06:18:17.002517 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000004 (ops 17-21)
I20260812 06:18:17.002559 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000005 (ops 22-26)
I20260812 06:18:17.002601 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000006 (ops 27-31)
I20260812 06:18:17.002643 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000007 (ops 32-36)
I20260812 06:18:17.002683 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000008 (ops 37-41)
I20260812 06:18:17.002722 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000009 (ops 42-46)
I20260812 06:18:17.002763 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000010 (ops 47-51)
I20260812 06:18:17.002804 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000011 (ops 52-56)
I20260812 06:18:17.002847 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000012 (ops 57-61)
I20260812 06:18:17.002887 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000013 (ops 62-66)
I20260812 06:18:17.027567 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: LogGCOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.025s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:17.028030 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=14.095187
I20260812 06:18:17.071980 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.044s	user 0.022s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20000,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.072681 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:17.107577 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.035s	user 0.015s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6049,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.108079 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:17.118737 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.119128 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:17.318858 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.200s	user 0.135s	sys 0.060s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":135,"lbm_read_time_us":15016,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34123,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":43264,"update_count":3000}
I20260812 06:18:17.319499 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=14.095187
I20260812 06:18:17.383450 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.064s	user 0.031s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22067,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.383919 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:17.394513 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4169,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.394964 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:17.573652 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.179s	user 0.109s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":207,"lbm_read_time_us":13002,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30080,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:18:17.574209 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=11.118625
I20260812 06:18:17.623533 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.049s	user 0.032s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19470,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:17.623993 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:17.636063 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3979,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.636469 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:17.653512 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.017s	user 0.000s	sys 0.014s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3596,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:17.654001 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:17.820533 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.166s	user 0.114s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1171,"lbm_read_time_us":12484,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27642,"lbm_writes_lt_1ms":543,"mutex_wait_us":331,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:18:17.821452 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=10.126437
I20260812 06:18:17.858634 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.037s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":16170,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:17.859169 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:17.875154 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5633,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.875800 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:18.000337 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.124s	user 0.111s	sys 0.013s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":743,"lbm_read_time_us":8498,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25677,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2000}
I20260812 06:18:18.001020 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=10.126437
I20260812 06:18:18.044919 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.044s	user 0.034s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20656,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:18:18.045426 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:18.056771 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4441,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.057185 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:18.180629 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.123s	user 0.087s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":169,"lbm_read_time_us":8971,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26061,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2000}
I20260812 06:18:18.181692 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=10.126437
I20260812 06:18:18.233161 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.051s	user 0.028s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21888,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:18.233757 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:18.246673 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.013s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4470,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.247180 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushMRSOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:18.278505 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushMRSOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.031s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":1459,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1611,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:18.279207 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling LogGCOp(23fedd2594d0499ba0580497b34ed684): free 112692317 bytes of WAL
I20260812 06:18:18.279485 19269 log_reader.cc:385] T 23fedd2594d0499ba0580497b34ed684: removed 11 log segments from log reader
I20260812 06:18:18.279534 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000014 (ops 67-71)
I20260812 06:18:18.279563 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000015 (ops 72-76)
I20260812 06:18:18.279625 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000016 (ops 77-81)
I20260812 06:18:18.279670 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000017 (ops 82-86)
I20260812 06:18:18.279709 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000018 (ops 87-91)
I20260812 06:18:18.279754 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000019 (ops 92-96)
I20260812 06:18:18.279796 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000020 (ops 97-101)
I20260812 06:18:18.279843 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000021 (ops 102-106)
I20260812 06:18:18.279883 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000022 (ops 107-111)
I20260812 06:18:18.279923 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000023 (ops 112-116)
I20260812 06:18:18.279963 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000024 (ops 117-121)
I20260812 06:18:18.304337 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: LogGCOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:18.304858 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling UndoDeltaBlockGCOp(23fedd2594d0499ba0580497b34ed684): 447 bytes on disk
I20260812 06:18:18.305399 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: UndoDeltaBlockGCOp(23fedd2594d0499ba0580497b34ed684) 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:18.305868 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=3.181125
I20260812 06:18:18.317597 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4441,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:18.318044 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:18.331749 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5126,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:18.332290 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:18.518029 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.186s	user 0.121s	sys 0.060s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":979,"lbm_read_time_us":12216,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40020,"lbm_writes_lt_1ms":643,"mutex_wait_us":296,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18944,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:18:18.518814 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=14.095187
I20260812 06:18:18.573889 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.055s	user 0.020s	sys 0.031s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":28465,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.574433 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:18.587026 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4564,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.587612 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:18.751320 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.164s	user 0.115s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":959,"lbm_read_time_us":11692,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29115,"lbm_writes_lt_1ms":543,"mutex_wait_us":308,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2500}
I20260812 06:18:18.751952 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=14.095187
I20260812 06:18:18.802469 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.050s	user 0.019s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25156,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.802971 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:18.954977 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.152s	user 0.089s	sys 0.052s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":219,"lbm_read_time_us":10280,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24566,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2000}
I20260812 06:18:18.955742 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=14.095187
I20260812 06:18:19.010743 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.052s	user 0.020s	sys 0.026s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22427,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.011260 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:19.021692 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3926,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.022414 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:19.213582 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.191s	user 0.130s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":677,"lbm_read_time_us":11870,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29570,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":64640,"update_count":2500}
I20260812 06:18:19.214251 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=14.095187
I20260812 06:18:19.265085 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.051s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20761,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.265690 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:19.277987 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4401,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.278466 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:19.434038 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.155s	user 0.112s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1601,"lbm_read_time_us":12132,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31316,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":389,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:18:19.434846 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=11.118625
I20260812 06:18:19.477355 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.042s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":17754,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:19.477927 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:19.497695 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.020s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4123,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:19.498157 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:19.510474 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4297,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.511291 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:19.655500 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.144s	user 0.113s	sys 0.027s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774797,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":412,"lbm_read_time_us":9218,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29099,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:19.656018 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=11.118625
I20260812 06:18:19.704877 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.049s	user 0.019s	sys 0.025s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":19091,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:19.705561 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:19.717530 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.012s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3965,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.718077 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:19.731514 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5231,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:19.732004 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushMRSOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:19.762174 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushMRSOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":291,"dirs.run_wall_time_us":1286,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1643,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31,"spinlock_wait_cycles":896}
I20260812 06:18:19.762887 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling LogGCOp(23fedd2594d0499ba0580497b34ed684): free 124710529 bytes of WAL
I20260812 06:18:19.763121 19269 log_reader.cc:385] T 23fedd2594d0499ba0580497b34ed684: removed 12 log segments from log reader
I20260812 06:18:19.763167 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000025 (ops 122-126)
I20260812 06:18:19.763197 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000026 (ops 127-131)
I20260812 06:18:19.763262 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000027 (ops 132-136)
I20260812 06:18:19.763295 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000028 (ops 137-141)
I20260812 06:18:19.763331 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000029 (ops 142-146)
I20260812 06:18:19.763411 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000030 (ops 147-151)
I20260812 06:18:19.763449 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000031 (ops 152-156)
I20260812 06:18:19.763499 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000032 (ops 157-161)
I20260812 06:18:19.763545 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000033 (ops 162-166)
I20260812 06:18:19.763584 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000034 (ops 167-171)
I20260812 06:18:19.763624 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000035 (ops 172-176)
I20260812 06:18:19.763670 19269 log.cc:1079] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/23fedd2594d0499ba0580497b34ed684/wal-000000036 (ops 177-181)
I20260812 06:18:19.791247 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: LogGCOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.028s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:18:19.791692 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling UndoDeltaBlockGCOp(23fedd2594d0499ba0580497b34ed684): 482 bytes on disk
I20260812 06:18:19.792268 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: UndoDeltaBlockGCOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:18:19.792835 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=3.181125
I20260812 06:18:19.805322 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4553934,"delete_count":0,"lbm_write_time_us":4943,"lbm_writes_lt_1ms":114,"reinsert_count":0,"update_count":555}
I20260812 06:18:19.805750 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:19.818348 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.012s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":3686,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:18:19.818882 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:20.056335 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.237s	user 0.125s	sys 0.099s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979859,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":222,"lbm_read_time_us":14157,"lbm_reads_lt_1ms":775,"lbm_write_time_us":40118,"lbm_writes_lt_1ms":743,"mutex_wait_us":23,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":20992,"thread_start_us":77,"threads_started":1,"update_count":3500}
I20260812 06:18:20.057127 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=18.063937
I20260812 06:18:20.127550 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.070s	user 0.039s	sys 0.031s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26958,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:20.128264 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684): perf score=2.188937
I20260812 06:18:20.145112 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: FlushDeltaMemStoresOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6365,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.145720 19383 maintenance_manager.cc:419] P 7ebc0a19a6424f91bb55e005510fa66c: Scheduling MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684): perf score=1.000000
I20260812 06:18:20.191865 19095 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.860s	user 1.756s	sys 0.157s
I20260812 06:18:20.266940 19095 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.074s	user 0.003s	sys 0.000s
I20260812 06:18:20.267763 19095 tablet_server.cc:179] TabletServer@127.18.165.193:0 shutting down...
I20260812 06:18:20.320945 19269 maintenance_manager.cc:643] P 7ebc0a19a6424f91bb55e005510fa66c: MajorDeltaCompactionOp(23fedd2594d0499ba0580497b34ed684) complete. Timing: real 0.175s	user 0.113s	sys 0.061s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":297,"lbm_read_time_us":15145,"lbm_reads_lt_1ms":668,"lbm_write_time_us":31624,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":3000}
I20260812 06:18:20.321679 19095 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:20.322190 19095 tablet_replica.cc:333] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c: stopping tablet replica
I20260812 06:18:20.322501 19095 raft_consensus.cc:2243] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:20.322748 19095 raft_consensus.cc:2272] T 23fedd2594d0499ba0580497b34ed684 P 7ebc0a19a6424f91bb55e005510fa66c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:20.329495 19095 tablet_server.cc:196] TabletServer@127.18.165.193:0 shutdown complete.
I20260812 06:18:20.373746 19095 master.cc:562] Master@127.18.165.254:40211 shutting down...
I20260812 06:18:20.377261 19095 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:20.377434 19095 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:20.377490 19095 tablet_replica.cc:333] T 00000000000000000000000000000000 P 996ae6bfc6c6402ba925e260079d94aa: stopping tablet replica
I20260812 06:18:20.389716 19095 master.cc:584] Master@127.18.165.254:40211 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5411 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:20.497570 19095 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.18.165.254:38257
I20260812 06:18:20.497932 19095 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:20.500036 19434 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:20.500169 19095 server_base.cc:1061] running on GCE node
W20260812 06:18:20.500120 19435 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:20.500046 19441 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:20.500427 19095 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:20.500469 19095 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:20.500484 19095 hybrid_clock.cc:648] HybridClock initialized: now 1786515500500485 us; error 0 us; skew 500 ppm
I20260812 06:18:20.501374 19095 webserver.cc:533] Webserver started at http://127.18.165.254:37445/ using document root <none> and password file <none>
I20260812 06:18:20.501557 19095 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:20.501611 19095 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:20.501715 19095 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:20.502127 19095 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/master-0-root/instance:
uuid: "671f51232a8f467394a5edb53a6f6e84"
format_stamp: "Formatted at 2026-08-12 06:18:20 on dist-test-slave-x4qh"
I20260812 06:18:20.503680 19095 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:20.504647 19451 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:20.504923 19095 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:20.504988 19095 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/master-0-root
uuid: "671f51232a8f467394a5edb53a6f6e84"
format_stamp: "Formatted at 2026-08-12 06:18:20 on dist-test-slave-x4qh"
I20260812 06:18:20.505086 19095 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-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:20.512816 19095 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:20.513221 19095 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:20.519266 19095 rpc_server.cc:307] RPC server started. Bound to: 127.18.165.254:38257
I20260812 06:18:20.527628 19544 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.165.254:38257 every 8 connection(s)
I20260812 06:18:20.528247 19546 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:20.530362 19546 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84: Bootstrap starting.
I20260812 06:18:20.531136 19546 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:20.532284 19546 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84: No bootstrap required, opened a new log
I20260812 06:18:20.532651 19546 raft_consensus.cc:359] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "671f51232a8f467394a5edb53a6f6e84" member_type: VOTER }
I20260812 06:18:20.532735 19546 raft_consensus.cc:385] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:20.532758 19546 raft_consensus.cc:740] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 671f51232a8f467394a5edb53a6f6e84, State: Initialized, Role: FOLLOWER
I20260812 06:18:20.532871 19546 consensus_queue.cc:260] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [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: "671f51232a8f467394a5edb53a6f6e84" member_type: VOTER }
I20260812 06:18:20.532928 19546 raft_consensus.cc:399] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:20.532950 19546 raft_consensus.cc:493] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:20.532985 19546 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:20.533681 19546 raft_consensus.cc:515] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "671f51232a8f467394a5edb53a6f6e84" member_type: VOTER }
I20260812 06:18:20.533800 19546 leader_election.cc:304] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [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: 671f51232a8f467394a5edb53a6f6e84; no voters: 
I20260812 06:18:20.533972 19546 leader_election.cc:290] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:20.534204 19549 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:20.534418 19546 sys_catalog.cc:565] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:20.534472 19549 raft_consensus.cc:697] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [term 1 LEADER]: Becoming Leader. State: Replica: 671f51232a8f467394a5edb53a6f6e84, State: Running, Role: LEADER
I20260812 06:18:20.534658 19549 consensus_queue.cc:237] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [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: "671f51232a8f467394a5edb53a6f6e84" member_type: VOTER }
I20260812 06:18:20.535462 19550 sys_catalog.cc:455] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "671f51232a8f467394a5edb53a6f6e84" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "671f51232a8f467394a5edb53a6f6e84" member_type: VOTER } }
I20260812 06:18:20.535601 19550 sys_catalog.cc:458] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:20.535452 19551 sys_catalog.cc:455] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 671f51232a8f467394a5edb53a6f6e84. Latest consensus state: current_term: 1 leader_uuid: "671f51232a8f467394a5edb53a6f6e84" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "671f51232a8f467394a5edb53a6f6e84" member_type: VOTER } }
I20260812 06:18:20.535956 19551 sys_catalog.cc:458] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:20.536302 19562 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:20.536511 19095 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:20.537067 19562 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:20.538781 19562 catalog_manager.cc:1383] Generated new cluster ID: 71a5c5a5da274a41b11981b97bedc938
I20260812 06:18:20.538849 19562 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:20.549686 19562 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:20.550264 19562 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:20.557022 19562 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84: Generated new TSK 0
I20260812 06:18:20.557219 19562 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:20.568881 19095 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:20.571041 19579 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:20.571064 19585 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:20.571147 19095 server_base.cc:1061] running on GCE node
W20260812 06:18:20.571136 19581 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:20.571468 19095 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:20.571532 19095 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:20.571560 19095 hybrid_clock.cc:648] HybridClock initialized: now 1786515500571559 us; error 0 us; skew 500 ppm
I20260812 06:18:20.572392 19095 webserver.cc:533] Webserver started at http://127.18.165.193:40635/ using document root <none> and password file <none>
I20260812 06:18:20.572578 19095 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:20.572651 19095 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:20.572729 19095 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:20.573141 19095 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/instance:
uuid: "2abfe71c6e97479193a777bfe11358fa"
format_stamp: "Formatted at 2026-08-12 06:18:20 on dist-test-slave-x4qh"
I20260812 06:18:20.574620 19095 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:20.575645 19600 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:20.575903 19095 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:20.575994 19095 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root
uuid: "2abfe71c6e97479193a777bfe11358fa"
format_stamp: "Formatted at 2026-08-12 06:18:20 on dist-test-slave-x4qh"
I20260812 06:18:20.576079 19095 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-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:20.593227 19095 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:20.593695 19095 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:20.594056 19095 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:20.594558 19095 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:20.594622 19095 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:20.594686 19095 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:20.594734 19095 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:20.599212 19095 rpc_server.cc:307] RPC server started. Bound to: 127.18.165.193:38439
I20260812 06:18:20.599296 19722 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.165.193:38439 every 8 connection(s)
I20260812 06:18:20.607457 19724 heartbeater.cc:344] Connected to a master server at 127.18.165.254:38257
I20260812 06:18:20.607580 19724 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:20.607793 19724 heartbeater.cc:507] Master 127.18.165.254:38257 requested a full tablet report, sending...
I20260812 06:18:20.608438 19483 ts_manager.cc:194] Registered new tserver with Master: 2abfe71c6e97479193a777bfe11358fa (127.18.165.193:38439)
I20260812 06:18:20.608554 19095 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008831011s
I20260812 06:18:20.609473 19483 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55620
I20260812 06:18:20.615788 19483 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55626:
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:20.624507 19651 tablet_service.cc:1511] Processing CreateTablet for tablet fad74618ec1144a194e98b3e142809c5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=326e01a913c840c78de815f5d490b961]), partition=
I20260812 06:18:20.624809 19651 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet fad74618ec1144a194e98b3e142809c5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:20.627058 19743 tablet_bootstrap.cc:492] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Bootstrap starting.
I20260812 06:18:20.627993 19743 tablet_bootstrap.cc:654] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:20.629001 19743 tablet_bootstrap.cc:492] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: No bootstrap required, opened a new log
I20260812 06:18:20.629081 19743 ts_tablet_manager.cc:1403] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:20.629454 19743 raft_consensus.cc:359] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2abfe71c6e97479193a777bfe11358fa" member_type: VOTER last_known_addr { host: "127.18.165.193" port: 38439 } }
I20260812 06:18:20.629539 19743 raft_consensus.cc:385] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:20.629560 19743 raft_consensus.cc:740] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2abfe71c6e97479193a777bfe11358fa, State: Initialized, Role: FOLLOWER
I20260812 06:18:20.629736 19743 consensus_queue.cc:260] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa [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: "2abfe71c6e97479193a777bfe11358fa" member_type: VOTER last_known_addr { host: "127.18.165.193" port: 38439 } }
I20260812 06:18:20.629841 19743 raft_consensus.cc:399] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:20.629890 19743 raft_consensus.cc:493] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:20.629951 19743 raft_consensus.cc:3060] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:20.630678 19743 raft_consensus.cc:515] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2abfe71c6e97479193a777bfe11358fa" member_type: VOTER last_known_addr { host: "127.18.165.193" port: 38439 } }
I20260812 06:18:20.630832 19743 leader_election.cc:304] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa [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: 2abfe71c6e97479193a777bfe11358fa; no voters: 
I20260812 06:18:20.631054 19743 leader_election.cc:290] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:20.631196 19747 raft_consensus.cc:2804] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:20.631451 19743 ts_tablet_manager.cc:1434] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:20.631455 19747 raft_consensus.cc:697] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa [term 1 LEADER]: Becoming Leader. State: Replica: 2abfe71c6e97479193a777bfe11358fa, State: Running, Role: LEADER
I20260812 06:18:20.631512 19724 heartbeater.cc:499] Master 127.18.165.254:38257 was elected leader, sending a full tablet report...
I20260812 06:18:20.631696 19747 consensus_queue.cc:237] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa [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: "2abfe71c6e97479193a777bfe11358fa" member_type: VOTER last_known_addr { host: "127.18.165.193" port: 38439 } }
I20260812 06:18:20.632897 19483 catalog_manager.cc:5719] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa reported cstate change: term changed from 0 to 1, leader changed from <none> to 2abfe71c6e97479193a777bfe11358fa (127.18.165.193). New cstate: current_term: 1 leader_uuid: "2abfe71c6e97479193a777bfe11358fa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2abfe71c6e97479193a777bfe11358fa" member_type: VOTER last_known_addr { host: "127.18.165.193" port: 38439 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:20.693637 19095 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.013s	sys 0.010s
I20260812 06:18:20.850265 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushMRSOp(fad74618ec1144a194e98b3e142809c5): perf score=19.054940
I20260812 06:18:21.011214 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushMRSOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.161s	user 0.093s	sys 0.062s Metrics: {"bytes_written":13127963,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":890,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42944,"lbm_writes_lt_1ms":787,"mutex_wait_us":841,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":896,"update_count":1600}
I20260812 06:18:21.011901 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling LogGCOp(fad74618ec1144a194e98b3e142809c5): free 20743880 bytes of WAL
I20260812 06:18:21.012135 19607 log_reader.cc:385] T fad74618ec1144a194e98b3e142809c5: removed 2 log segments from log reader
I20260812 06:18:21.012185 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000001 (ops 1-6)
I20260812 06:18:21.012216 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000002 (ops 7-11)
I20260812 06:18:21.016458 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: LogGCOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:21.016762 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling UndoDeltaBlockGCOp(fad74618ec1144a194e98b3e142809c5): 16821650 bytes on disk
I20260812 06:18:21.017158 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: UndoDeltaBlockGCOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:18:21.017506 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=3.181125
I20260812 06:18:21.033253 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.016s	user 0.009s	sys 0.005s Metrics: {"bytes_written":5210314,"delete_count":0,"lbm_write_time_us":6367,"lbm_writes_lt_1ms":130,"reinsert_count":0,"update_count":635}
I20260812 06:18:21.033727 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:21.042232 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.008s	user 0.003s	sys 0.003s Metrics: {"bytes_written":1764227,"delete_count":0,"lbm_write_time_us":2803,"lbm_writes_lt_1ms":46,"reinsert_count":0,"update_count":215}
I20260812 06:18:21.042725 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:21.227452 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.185s	user 0.132s	sys 0.052s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405500,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":734,"lbm_read_time_us":12850,"lbm_reads_lt_1ms":559,"lbm_write_time_us":30170,"lbm_writes_lt_1ms":533,"mutex_wait_us":1,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":4480,"thread_start_us":327,"threads_started":5,"update_count":2450}
I20260812 06:18:21.228155 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=14.095187
I20260812 06:18:21.279623 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.051s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21219,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.280202 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:21.448163 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.168s	user 0.116s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":905,"lbm_read_time_us":13900,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25773,"lbm_writes_lt_1ms":443,"mutex_wait_us":305,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":35328,"update_count":2000}
I20260812 06:18:21.448844 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=11.118625
I20260812 06:18:21.488457 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.039s	user 0.018s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17358,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:21.488947 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:21.512445 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.023s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4811,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:21.513067 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:21.527590 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.014s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5716,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.528016 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:21.725066 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.197s	user 0.137s	sys 0.054s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":208,"lbm_read_time_us":10939,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32795,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:18:21.725803 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=14.095187
I20260812 06:18:21.775990 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.050s	user 0.022s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24928,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.776542 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:21.790199 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5589,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.790663 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:21.947912 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.157s	user 0.131s	sys 0.017s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":372,"lbm_read_time_us":9624,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29647,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27136,"update_count":2500}
I20260812 06:18:21.948680 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=14.095187
I20260812 06:18:21.998020 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.049s	user 0.022s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18359,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.998544 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:22.010437 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4429,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.010874 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:22.170500 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.159s	user 0.108s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":241,"lbm_read_time_us":10692,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31632,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":53248,"update_count":2500}
I20260812 06:18:22.171160 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=14.095187
I20260812 06:18:22.224611 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.053s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21100,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:22.225117 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:22.236675 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4163,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.237350 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushMRSOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:22.266134 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushMRSOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":264,"dirs.run_wall_time_us":1179,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1590,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:22.266685 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling LogGCOp(fad74618ec1144a194e98b3e142809c5): free 112239323 bytes of WAL
I20260812 06:18:22.266913 19607 log_reader.cc:385] T fad74618ec1144a194e98b3e142809c5: removed 11 log segments from log reader
I20260812 06:18:22.266961 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000003 (ops 12-16)
I20260812 06:18:22.266989 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000004 (ops 17-21)
I20260812 06:18:22.267055 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000005 (ops 22-26)
I20260812 06:18:22.267084 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000006 (ops 27-31)
I20260812 06:18:22.267124 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000007 (ops 32-36)
I20260812 06:18:22.267186 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000008 (ops 37-41)
I20260812 06:18:22.267226 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000009 (ops 42-46)
I20260812 06:18:22.267267 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000010 (ops 47-50)
I20260812 06:18:22.267305 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000011 (ops 51-55)
I20260812 06:18:22.267341 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000012 (ops 56-60)
I20260812 06:18:22.267405 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000013 (ops 61-65)
I20260812 06:18:22.293081 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: LogGCOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.026s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:18:22.293533 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=3.181125
I20260812 06:18:22.305642 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4808,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:22.306157 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling LogGCOp(fad74618ec1144a194e98b3e142809c5): free 12017932 bytes of WAL
I20260812 06:18:22.306370 19607 log_reader.cc:385] T fad74618ec1144a194e98b3e142809c5: removed 1 log segments from log reader
I20260812 06:18:22.306424 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000014 (ops 66-70)
I20260812 06:18:22.308877 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: LogGCOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:22.309170 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling UndoDeltaBlockGCOp(fad74618ec1144a194e98b3e142809c5): 447 bytes on disk
I20260812 06:18:22.309554 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: UndoDeltaBlockGCOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:18:22.309994 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:22.321244 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4132,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:22.321684 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:22.552075 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.230s	user 0.155s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020731,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":512,"lbm_read_time_us":15863,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38657,"lbm_writes_lt_1ms":743,"mutex_wait_us":52,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":114176,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:18:22.554708 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=18.063937
I20260812 06:18:22.637563 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.082s	user 0.032s	sys 0.039s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":32338,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:22.638123 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=3.181125
I20260812 06:18:22.650733 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4971,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:22.651264 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:22.664842 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5222,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:22.665387 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:22.905910 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.240s	user 0.167s	sys 0.068s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020620,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":114,"lbm_read_time_us":16969,"lbm_reads_lt_1ms":773,"lbm_write_time_us":40816,"lbm_writes_lt_1ms":743,"mutex_wait_us":73,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":3500}
I20260812 06:18:22.906615 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=18.063937
I20260812 06:18:22.975718 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.069s	user 0.042s	sys 0.026s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":30768,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:22.976229 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:22.992483 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6212,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.993080 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:23.189244 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.196s	user 0.143s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":806,"lbm_read_time_us":14964,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35125,"lbm_writes_lt_1ms":643,"mutex_wait_us":638,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:18:23.190033 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=14.095187
I20260812 06:18:23.245028 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.054s	user 0.029s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24811,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.245522 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:23.257072 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.011s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4742,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.257616 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:23.424268 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.166s	user 0.126s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2187,"lbm_read_time_us":10623,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33544,"lbm_writes_lt_1ms":543,"mutex_wait_us":781,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:18:23.425012 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=12.110812
I20260812 06:18:23.467722 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.043s	user 0.022s	sys 0.020s Metrics: {"bytes_written":13989480,"delete_count":0,"lbm_write_time_us":19185,"lbm_writes_lt_1ms":344,"reinsert_count":0,"update_count":1705}
I20260812 06:18:23.468351 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=1.196750
I20260812 06:18:23.480647 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":2830884,"delete_count":0,"lbm_write_time_us":3987,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:18:23.481170 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:23.636961 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.156s	user 0.096s	sys 0.052s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21123487,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":214,"lbm_read_time_us":11569,"lbm_reads_lt_1ms":474,"lbm_write_time_us":25258,"lbm_writes_lt_1ms":453,"mutex_wait_us":22,"peak_mem_usage":51099678,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2050}
I20260812 06:18:23.637699 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=14.095187
I20260812 06:18:23.686053 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.048s	user 0.017s	sys 0.027s Metrics: {"bytes_written":15999660,"delete_count":0,"lbm_write_time_us":20748,"lbm_writes_lt_1ms":393,"reinsert_count":0,"update_count":1950}
I20260812 06:18:23.686590 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:23.706432 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.020s	user 0.000s	sys 0.016s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4190,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.707059 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushMRSOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:23.744465 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushMRSOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.037s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":182,"dirs.run_wall_time_us":1504,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2177,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:23.745165 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling LogGCOp(fad74618ec1144a194e98b3e142809c5): free 112239323 bytes of WAL
I20260812 06:18:23.745383 19607 log_reader.cc:385] T fad74618ec1144a194e98b3e142809c5: removed 11 log segments from log reader
I20260812 06:18:23.745428 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000015 (ops 71-75)
I20260812 06:18:23.745456 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000016 (ops 76-80)
I20260812 06:18:23.745515 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000017 (ops 81-84)
I20260812 06:18:23.745563 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000018 (ops 85-89)
I20260812 06:18:23.745602 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000019 (ops 90-94)
I20260812 06:18:23.745651 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000020 (ops 95-99)
I20260812 06:18:23.745692 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000021 (ops 100-104)
I20260812 06:18:23.745731 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000022 (ops 105-109)
I20260812 06:18:23.745772 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000023 (ops 110-114)
I20260812 06:18:23.745813 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000024 (ops 115-119)
I20260812 06:18:23.745860 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000025 (ops 120-124)
I20260812 06:18:23.768826 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: LogGCOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.023s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:23.769218 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling UndoDeltaBlockGCOp(fad74618ec1144a194e98b3e142809c5): 462 bytes on disk
I20260812 06:18:23.769649 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: UndoDeltaBlockGCOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:18:23.770151 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:23.793560 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.023s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6223,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.794051 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:23.804620 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3993,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.805150 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:24.034572 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.229s	user 0.117s	sys 0.111s Metrics: {"cfile_cache_miss":724,"cfile_cache_miss_bytes":32610503,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":823,"lbm_read_time_us":14065,"lbm_reads_lt_1ms":764,"lbm_write_time_us":40541,"lbm_writes_lt_1ms":733,"mutex_wait_us":287,"peak_mem_usage":86518310,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":78,"threads_started":1,"update_count":3450}
I20260812 06:18:24.035240 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=18.063937
I20260812 06:18:24.107553 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.072s	user 0.035s	sys 0.027s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":28105,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:24.108001 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:24.119459 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4041,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.119936 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:24.340147 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.220s	user 0.141s	sys 0.075s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":326,"lbm_read_time_us":13301,"lbm_reads_lt_1ms":672,"lbm_write_time_us":39563,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":3000}
I20260812 06:18:24.341010 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=15.087375
I20260812 06:18:24.398727 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.058s	user 0.035s	sys 0.016s Metrics: {"bytes_written":17394484,"delete_count":0,"lbm_write_time_us":24492,"lbm_writes_lt_1ms":427,"reinsert_count":0,"update_count":2120}
I20260812 06:18:24.399457 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:24.410157 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.011s	user 0.006s	sys 0.001s Metrics: {"bytes_written":3528309,"delete_count":0,"lbm_write_time_us":3512,"lbm_writes_lt_1ms":89,"reinsert_count":0,"update_count":430}
I20260812 06:18:24.410598 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:24.420034 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3609,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:24.420442 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:24.618112 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.197s	user 0.125s	sys 0.072s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918193,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":668,"lbm_read_time_us":13214,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32274,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":3000}
I20260812 06:18:24.618747 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=14.095187
I20260812 06:18:24.666251 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.047s	user 0.021s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20835,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.666983 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:24.681059 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5037,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.681535 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:24.860747 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.179s	user 0.120s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1032,"lbm_read_time_us":11669,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29515,"lbm_writes_lt_1ms":543,"mutex_wait_us":322,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:18:24.861387 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=15.087375
I20260812 06:18:24.933818 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.072s	user 0.029s	sys 0.028s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":25926,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:18:24.934414 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=6.157687
I20260812 06:18:24.965771 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.031s	user 0.000s	sys 0.024s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":11313,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:24.966354 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:25.180171 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.214s	user 0.143s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1015,"lbm_read_time_us":14715,"lbm_reads_lt_1ms":664,"lbm_write_time_us":36472,"lbm_writes_lt_1ms":643,"mutex_wait_us":353,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18816,"update_count":3000}
I20260812 06:18:25.180756 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=18.063937
I20260812 06:18:25.240005 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.059s	user 0.026s	sys 0.028s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":25316,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:25.240518 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushMRSOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:25.279165 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushMRSOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.038s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":95,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1360,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2517,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:25.280016 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=3.181125
I20260812 06:18:25.292181 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4458,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:25.292665 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling LogGCOp(fad74618ec1144a194e98b3e142809c5): free 129320714 bytes of WAL
I20260812 06:18:25.292893 19607 log_reader.cc:385] T fad74618ec1144a194e98b3e142809c5: removed 13 log segments from log reader
I20260812 06:18:25.292937 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000026 (ops 125-129)
I20260812 06:18:25.292969 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000027 (ops 130-134)
I20260812 06:18:25.293035 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000028 (ops 135-139)
I20260812 06:18:25.293092 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000029 (ops 140-144)
I20260812 06:18:25.293133 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000030 (ops 145-149)
I20260812 06:18:25.293175 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000031 (ops 150-154)
I20260812 06:18:25.293215 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000032 (ops 155-158)
I20260812 06:18:25.293252 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000033 (ops 159-163)
I20260812 06:18:25.293289 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000034 (ops 164-168)
I20260812 06:18:25.293329 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000035 (ops 169-173)
I20260812 06:18:25.293358 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000036 (ops 174-178)
I20260812 06:18:25.293398 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000037 (ops 179-182)
I20260812 06:18:25.293422 19607 log.cc:1079] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: Deleting log segment in path: /tmp/dist-test-taskvziC_Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515495063162-19095-0/minicluster-data/ts-0-root/wals/fad74618ec1144a194e98b3e142809c5/wal-000000038 (ops 183-187)
I20260812 06:18:25.321372 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: LogGCOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.029s	user 0.004s	sys 0.023s Metrics: {}
I20260812 06:18:25.321894 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling UndoDeltaBlockGCOp(fad74618ec1144a194e98b3e142809c5): 483 bytes on disk
I20260812 06:18:25.322319 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: UndoDeltaBlockGCOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:25.322973 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:25.337273 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.014s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4371,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.337699 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=2.188937
I20260812 06:18:25.347597 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3625,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:25.348042 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:25.579592 19095 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.886s	user 1.819s	sys 0.191s
I20260812 06:18:25.596392 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.248s	user 0.183s	sys 0.064s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37123152,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":18466,"lbm_reads_lt_1ms":870,"lbm_write_time_us":46717,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":4000}
I20260812 06:18:25.596928 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5): perf score=18.063937
I20260812 06:18:25.637508 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: FlushDeltaMemStoresOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.040s	user 0.032s	sys 0.007s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":19902,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:25.637964 19725 maintenance_manager.cc:419] P 2abfe71c6e97479193a777bfe11358fa: Scheduling MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5): perf score=1.000000
I20260812 06:18:25.659615 19095 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.080s	user 0.002s	sys 0.000s
I20260812 06:18:25.660153 19095 tablet_server.cc:179] TabletServer@127.18.165.193:0 shutting down...
I20260812 06:18:25.775722 19607 maintenance_manager.cc:643] P 2abfe71c6e97479193a777bfe11358fa: MajorDeltaCompactionOp(fad74618ec1144a194e98b3e142809c5) complete. Timing: real 0.138s	user 0.103s	sys 0.032s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24815566,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":3140,"lbm_read_time_us":11710,"lbm_reads_lt_1ms":567,"lbm_write_time_us":29725,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":2273,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:25.776456 19095 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:25.776687 19095 tablet_replica.cc:333] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa: stopping tablet replica
I20260812 06:18:25.776904 19095 raft_consensus.cc:2243] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:25.777112 19095 raft_consensus.cc:2272] T fad74618ec1144a194e98b3e142809c5 P 2abfe71c6e97479193a777bfe11358fa [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:25.781298 19095 tablet_server.cc:196] TabletServer@127.18.165.193:0 shutdown complete.
I20260812 06:18:25.818807 19095 master.cc:562] Master@127.18.165.254:38257 shutting down...
I20260812 06:18:25.822381 19095 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:25.822594 19095 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:25.822695 19095 tablet_replica.cc:333] T 00000000000000000000000000000000 P 671f51232a8f467394a5edb53a6f6e84: stopping tablet replica
I20260812 06:18:25.835242 19095 master.cc:584] Master@127.18.165.254:38257 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5443 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10855 ms total)

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