[==========] 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:17:43.779947 13025 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.184.126:46727
I20260812 06:17:43.781093 13025 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:17:43.781754 13025 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:43.789495 13025 server_base.cc:1061] running on GCE node
W20260812 06:17:43.789464 13034 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:17:43.789811 13032 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:17:43.789821 13036 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:17:43.790714 13025 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:43.790822 13025 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:17:43.790891 13025 hybrid_clock.cc:648] HybridClock initialized: now 1786515463790889 us; error 0 us; skew 500 ppm
I20260812 06:17:43.793128 13025 webserver.cc:533] Webserver started at http://127.12.184.126:36323/ using document root <none> and password file <none>
I20260812 06:17:43.793879 13025 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:43.793970 13025 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:43.794322 13025 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:43.796317 13025 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/master-0-root/instance:
uuid: "1bed081ac2dc4f968ef356d4dfb99687"
format_stamp: "Formatted at 2026-08-12 06:17:43 on dist-test-slave-dhph"
I20260812 06:17:43.800890 13025 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.004s	sys 0.001s
I20260812 06:17:43.803992 13041 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:17:43.805598 13025 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:17:43.805851 13025 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/master-0-root
uuid: "1bed081ac2dc4f968ef356d4dfb99687"
format_stamp: "Formatted at 2026-08-12 06:17:43 on dist-test-slave-dhph"
I20260812 06:17:43.805992 13025 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-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:17:43.842573 13025 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:43.843489 13025 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:17:43.843719 13025 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:43.855427 13025 rpc_server.cc:307] RPC server started. Bound to: 127.12.184.126:46727
I20260812 06:17:43.855435 13104 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.184.126:46727 every 8 connection(s)
I20260812 06:17:43.858543 13106 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:17:43.865329 13106 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687: Bootstrap starting.
I20260812 06:17:43.868157 13106 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:43.869242 13106 log.cc:826] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:43.871357 13106 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687: No bootstrap required, opened a new log
I20260812 06:17:43.874462 13106 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1bed081ac2dc4f968ef356d4dfb99687" member_type: VOTER }
I20260812 06:17:43.875020 13106 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:43.875180 13106 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1bed081ac2dc4f968ef356d4dfb99687, State: Initialized, Role: FOLLOWER
I20260812 06:17:43.876116 13106 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [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: "1bed081ac2dc4f968ef356d4dfb99687" member_type: VOTER }
I20260812 06:17:43.876353 13106 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:43.876451 13106 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:43.876647 13106 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:43.878537 13106 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1bed081ac2dc4f968ef356d4dfb99687" member_type: VOTER }
I20260812 06:17:43.879526 13106 leader_election.cc:304] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [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: 1bed081ac2dc4f968ef356d4dfb99687; no voters: 
I20260812 06:17:43.879993 13106 leader_election.cc:290] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:43.880426 13111 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:43.880988 13111 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [term 1 LEADER]: Becoming Leader. State: Replica: 1bed081ac2dc4f968ef356d4dfb99687, State: Running, Role: LEADER
I20260812 06:17:43.881227 13106 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:43.881637 13111 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [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: "1bed081ac2dc4f968ef356d4dfb99687" member_type: VOTER }
I20260812 06:17:43.884454 13115 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1bed081ac2dc4f968ef356d4dfb99687. Latest consensus state: current_term: 1 leader_uuid: "1bed081ac2dc4f968ef356d4dfb99687" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1bed081ac2dc4f968ef356d4dfb99687" member_type: VOTER } }
I20260812 06:17:43.884433 13114 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1bed081ac2dc4f968ef356d4dfb99687" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1bed081ac2dc4f968ef356d4dfb99687" member_type: VOTER } }
I20260812 06:17:43.884635 13115 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:43.884635 13114 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:43.884856 13025 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:43.887985 13128 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:43.888101 13128 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:43.888218 13129 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:43.890077 13129 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:43.897316 13129 catalog_manager.cc:1383] Generated new cluster ID: 449350261e1b46f28e3a8ec5f6fe08b4
I20260812 06:17:43.897456 13129 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:43.918629 13129 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:43.919616 13129 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:43.926788 13129 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687: Generated new TSK 0
I20260812 06:17:43.927522 13129 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:43.950417 13025 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:43.954092 13135 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:17:43.954093 13134 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:17:43.954566 13137 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:17:43.954645 13025 server_base.cc:1061] running on GCE node
I20260812 06:17:43.954908 13025 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:43.954959 13025 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:17:43.954978 13025 hybrid_clock.cc:648] HybridClock initialized: now 1786515463954978 us; error 0 us; skew 500 ppm
I20260812 06:17:43.956458 13025 webserver.cc:533] Webserver started at http://127.12.184.65:37817/ using document root <none> and password file <none>
I20260812 06:17:43.956638 13025 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:43.956715 13025 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:43.956832 13025 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:43.957298 13025 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/instance:
uuid: "49da6b1811ae4f12a0870e939391b26e"
format_stamp: "Formatted at 2026-08-12 06:17:43 on dist-test-slave-dhph"
I20260812 06:17:43.959657 13025 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:43.960944 13142 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:17:43.961229 13025 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:43.961305 13025 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root
uuid: "49da6b1811ae4f12a0870e939391b26e"
format_stamp: "Formatted at 2026-08-12 06:17:43 on dist-test-slave-dhph"
I20260812 06:17:43.961418 13025 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-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:17:43.974983 13025 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:43.975520 13025 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:43.976110 13025 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:43.977298 13025 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:43.977366 13025 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:43.977417 13025 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:43.977435 13025 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:43.986972 13025 rpc_server.cc:307] RPC server started. Bound to: 127.12.184.65:37989
I20260812 06:17:43.987047 13215 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.184.65:37989 every 8 connection(s)
I20260812 06:17:44.003608 13216 heartbeater.cc:344] Connected to a master server at 127.12.184.126:46727
I20260812 06:17:44.003921 13216 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:44.004470 13216 heartbeater.cc:507] Master 127.12.184.126:46727 requested a full tablet report, sending...
I20260812 06:17:44.006160 13057 ts_manager.cc:194] Registered new tserver with Master: 49da6b1811ae4f12a0870e939391b26e (127.12.184.65:37989)
I20260812 06:17:44.006999 13025 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.019262276s
I20260812 06:17:44.007768 13057 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:53712
I20260812 06:17:44.019274 13057 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:53714:
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:17:44.035317 13172 tablet_service.cc:1511] Processing CreateTablet for tablet 7d82ea284af14c90a5f9bd0ce8b9366d (DEFAULT_TABLE table=heavy-update-compaction-test [id=169bd26b268e473582cf1a58b80f594c]), partition=
I20260812 06:17:44.035986 13172 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 7d82ea284af14c90a5f9bd0ce8b9366d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:44.038938 13229 tablet_bootstrap.cc:492] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Bootstrap starting.
I20260812 06:17:44.040401 13229 tablet_bootstrap.cc:654] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:44.041787 13229 tablet_bootstrap.cc:492] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: No bootstrap required, opened a new log
I20260812 06:17:44.041944 13229 ts_tablet_manager.cc:1403] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:44.042565 13229 raft_consensus.cc:359] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "49da6b1811ae4f12a0870e939391b26e" member_type: VOTER last_known_addr { host: "127.12.184.65" port: 37989 } }
I20260812 06:17:44.042865 13229 raft_consensus.cc:385] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:44.042932 13229 raft_consensus.cc:740] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 49da6b1811ae4f12a0870e939391b26e, State: Initialized, Role: FOLLOWER
I20260812 06:17:44.043213 13229 consensus_queue.cc:260] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e [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: "49da6b1811ae4f12a0870e939391b26e" member_type: VOTER last_known_addr { host: "127.12.184.65" port: 37989 } }
I20260812 06:17:44.043332 13229 raft_consensus.cc:399] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:44.043365 13229 raft_consensus.cc:493] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:44.043429 13229 raft_consensus.cc:3060] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:44.044325 13229 raft_consensus.cc:515] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "49da6b1811ae4f12a0870e939391b26e" member_type: VOTER last_known_addr { host: "127.12.184.65" port: 37989 } }
I20260812 06:17:44.044713 13229 leader_election.cc:304] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e [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: 49da6b1811ae4f12a0870e939391b26e; no voters: 
I20260812 06:17:44.045039 13229 leader_election.cc:290] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:44.045193 13231 raft_consensus.cc:2804] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:44.045492 13231 raft_consensus.cc:697] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e [term 1 LEADER]: Becoming Leader. State: Replica: 49da6b1811ae4f12a0870e939391b26e, State: Running, Role: LEADER
I20260812 06:17:44.045511 13229 ts_tablet_manager.cc:1434] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.004s
I20260812 06:17:44.045783 13216 heartbeater.cc:499] Master 127.12.184.126:46727 was elected leader, sending a full tablet report...
I20260812 06:17:44.046245 13231 consensus_queue.cc:237] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e [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: "49da6b1811ae4f12a0870e939391b26e" member_type: VOTER last_known_addr { host: "127.12.184.65" port: 37989 } }
I20260812 06:17:44.049891 13057 catalog_manager.cc:5719] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e reported cstate change: term changed from 0 to 1, leader changed from <none> to 49da6b1811ae4f12a0870e939391b26e (127.12.184.65). New cstate: current_term: 1 leader_uuid: "49da6b1811ae4f12a0870e939391b26e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "49da6b1811ae4f12a0870e939391b26e" member_type: VOTER last_known_addr { host: "127.12.184.65" port: 37989 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:44.138026 13025 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.075s	user 0.022s	sys 0.016s
I20260812 06:17:44.238971 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushMRSOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=10.125253
I20260812 06:17:44.405699 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushMRSOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.166s	user 0.125s	sys 0.036s Metrics: {"bytes_written":8492251,"cfile_init":1,"compiler_manager_pool.queue_time_us":268,"delete_count":0,"dirs.queue_time_us":114,"dirs.run_cpu_time_us":296,"dirs.run_wall_time_us":1558,"drs_written":1,"lbm_read_time_us":151,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34973,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":463,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"spinlock_wait_cycles":141056,"thread_start_us":180,"threads_started":1,"update_count":1035}
I20260812 06:17:44.407003 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling LogGCOp(7d82ea284af14c90a5f9bd0ce8b9366d): free 11976772 bytes of WAL
I20260812 06:17:44.407330 13147 log_reader.cc:385] T 7d82ea284af14c90a5f9bd0ce8b9366d: removed 1 log segments from log reader
I20260812 06:17:44.407413 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000001 (ops 1-6)
I20260812 06:17:44.410219 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: LogGCOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:44.410741 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:44.426957 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":5631,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:17:44.427518 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling UndoDeltaBlockGCOp(7d82ea284af14c90a5f9bd0ce8b9366d): 8206539 bytes on disk
I20260812 06:17:44.428186 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: UndoDeltaBlockGCOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:17:44.428653 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:44.586416 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.157s	user 0.113s	sys 0.028s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487933,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":687,"lbm_read_time_us":9397,"lbm_reads_lt_1ms":360,"lbm_write_time_us":24082,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":350,"threads_started":5,"update_count":1500}
I20260812 06:17:44.587144 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=10.126437
I20260812 06:17:44.655686 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.068s	user 0.015s	sys 0.035s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23224,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:44.656529 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:44.673418 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.017s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5076,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.674059 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:44.859498 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.185s	user 0.143s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2152,"lbm_read_time_us":11073,"lbm_reads_lt_1ms":472,"lbm_write_time_us":34736,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:44.860164 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=10.126437
I20260812 06:17:44.906994 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.046s	user 0.034s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20121,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:44.907541 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:44.934510 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.027s	user 0.012s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6910,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.935575 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:45.140386 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.205s	user 0.141s	sys 0.061s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1001,"lbm_read_time_us":13553,"lbm_reads_lt_1ms":472,"lbm_write_time_us":33461,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":430,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:17:45.141129 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=11.118625
I20260812 06:17:45.190686 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.049s	user 0.037s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":21131,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:45.191958 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:45.206300 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.014s	user 0.000s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4954,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:45.207060 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:45.354406 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.147s	user 0.115s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":168,"lbm_read_time_us":10256,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27971,"lbm_writes_lt_1ms":443,"mutex_wait_us":83,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":67328,"update_count":2000}
I20260812 06:17:45.355129 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=10.126437
I20260812 06:17:45.418390 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.063s	user 0.029s	sys 0.019s Metrics: {"bytes_written":12307578,"delete_count":0,"lbm_write_time_us":22327,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:45.419275 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:45.430867 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3979,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.431468 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:45.596668 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.165s	user 0.144s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590434,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":926,"lbm_read_time_us":10883,"lbm_reads_lt_1ms":472,"lbm_write_time_us":36525,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:17:45.597398 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=10.126437
I20260812 06:17:45.659654 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.062s	user 0.034s	sys 0.027s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":22740,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:45.660331 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:45.676944 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6308,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.677515 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:45.862421 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.185s	user 0.124s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1214,"lbm_read_time_us":13503,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30356,"lbm_writes_lt_1ms":443,"mutex_wait_us":339,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:45.863358 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=10.126437
I20260812 06:17:45.913314 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.050s	user 0.034s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21211,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:45.913976 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:45.927686 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5255,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.928263 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:46.079998 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.151s	user 0.120s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590346,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":569,"lbm_read_time_us":10853,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27747,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":31744,"update_count":2000}
I20260812 06:17:46.080834 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=10.126437
I20260812 06:17:46.132609 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.052s	user 0.036s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19962,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:46.133350 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:46.145830 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4887,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.147099 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushMRSOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:46.187738 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushMRSOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.040s	user 0.034s	sys 0.003s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":192,"dirs.run_cpu_time_us":285,"dirs.run_wall_time_us":2672,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2267,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:46.189373 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling LogGCOp(7d82ea284af14c90a5f9bd0ce8b9366d): free 129320452 bytes of WAL
I20260812 06:17:46.190032 13147 log_reader.cc:385] T 7d82ea284af14c90a5f9bd0ce8b9366d: removed 13 log segments from log reader
I20260812 06:17:46.190119 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000002 (ops 7-11)
I20260812 06:17:46.190183 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000003 (ops 12-16)
I20260812 06:17:46.190239 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000004 (ops 17-20)
I20260812 06:17:46.190292 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000005 (ops 21-25)
I20260812 06:17:46.190404 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000006 (ops 26-30)
I20260812 06:17:46.190461 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000007 (ops 31-35)
I20260812 06:17:46.190511 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000008 (ops 36-40)
I20260812 06:17:46.190559 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000009 (ops 41-44)
I20260812 06:17:46.190639 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000010 (ops 45-49)
I20260812 06:17:46.190706 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000011 (ops 50-54)
I20260812 06:17:46.190747 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000012 (ops 55-59)
I20260812 06:17:46.190785 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000013 (ops 60-64)
I20260812 06:17:46.190822 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000014 (ops 65-69)
I20260812 06:17:46.220875 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: LogGCOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.031s	user 0.004s	sys 0.024s Metrics: {}
I20260812 06:17:46.221500 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=3.181125
I20260812 06:17:46.239842 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.018s	user 0.008s	sys 0.006s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5718,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:46.240396 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:46.256135 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5167,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:46.257120 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling UndoDeltaBlockGCOp(7d82ea284af14c90a5f9bd0ce8b9366d): 482 bytes on disk
I20260812 06:17:46.257660 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: UndoDeltaBlockGCOp(7d82ea284af14c90a5f9bd0ce8b9366d) 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:17:46.258307 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:46.477146 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.218s	user 0.161s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795398,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1379,"lbm_read_time_us":15170,"lbm_reads_lt_1ms":674,"lbm_write_time_us":41006,"lbm_writes_lt_1ms":643,"mutex_wait_us":317,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":23552,"thread_start_us":105,"threads_started":1,"update_count":3000}
I20260812 06:17:46.478142 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=14.095187
I20260812 06:17:46.546561 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.068s	user 0.026s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26877,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:46.547295 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:46.561615 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4615,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.562213 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:46.751432 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.189s	user 0.143s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1380,"lbm_read_time_us":12766,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34821,"lbm_writes_lt_1ms":543,"mutex_wait_us":726,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20352,"update_count":2500}
I20260812 06:17:46.752560 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=12.110812
I20260812 06:17:46.806921 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.054s	user 0.038s	sys 0.016s Metrics: {"bytes_written":14030496,"delete_count":0,"lbm_write_time_us":24719,"lbm_writes_lt_1ms":345,"reinsert_count":0,"update_count":1710}
I20260812 06:17:46.807606 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.196750
I20260812 06:17:46.842248 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.034s	user 0.014s	sys 0.000s Metrics: {"bytes_written":2379604,"delete_count":0,"lbm_write_time_us":6630,"lbm_writes_lt_1ms":61,"reinsert_count":0,"update_count":290}
I20260812 06:17:46.842854 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:46.858958 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5173,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.860000 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:47.099079 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.239s	user 0.161s	sys 0.068s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692829,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":470,"lbm_read_time_us":17733,"lbm_reads_lt_1ms":573,"lbm_write_time_us":40052,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:17:47.099757 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=14.095187
I20260812 06:17:47.166078 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.066s	user 0.033s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27051,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:47.166654 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:47.342353 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.176s	user 0.120s	sys 0.053s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20590227,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1664,"lbm_read_time_us":11494,"lbm_reads_lt_1ms":463,"lbm_write_time_us":28722,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:17:47.343107 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=11.118625
I20260812 06:17:47.402256 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.059s	user 0.022s	sys 0.024s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":32278,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:47.403213 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:47.423266 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.020s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4348,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:47.424166 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:47.437201 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.013s	user 0.000s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4880,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.437938 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:47.627570 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.189s	user 0.147s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692870,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":303,"lbm_read_time_us":12827,"lbm_reads_lt_1ms":573,"lbm_write_time_us":35632,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2500}
I20260812 06:17:47.628644 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=10.126437
I20260812 06:17:47.688583 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.060s	user 0.030s	sys 0.020s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":24288,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"mutex_wait_us":176,"reinsert_count":0,"update_count":1500}
I20260812 06:17:47.689327 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:47.706898 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.017s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6451,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.707679 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:47.888796 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.181s	user 0.136s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590346,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":811,"lbm_read_time_us":11203,"lbm_reads_lt_1ms":472,"lbm_write_time_us":36924,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":441,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:17:47.889652 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=10.126437
I20260812 06:17:47.957131 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.066s	user 0.031s	sys 0.023s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":24170,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:47.959659 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:47.979944 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.019s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6014,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.980835 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushMRSOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:48.036674 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushMRSOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.056s	user 0.050s	sys 0.003s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":186,"dirs.run_cpu_time_us":514,"dirs.run_wall_time_us":3520,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1957,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:48.037714 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling LogGCOp(7d82ea284af14c90a5f9bd0ce8b9366d): free 112692429 bytes of WAL
I20260812 06:17:48.037986 13147 log_reader.cc:385] T 7d82ea284af14c90a5f9bd0ce8b9366d: removed 11 log segments from log reader
I20260812 06:17:48.038293 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000015 (ops 70-74)
I20260812 06:17:48.038700 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000016 (ops 75-79)
I20260812 06:17:48.038786 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000017 (ops 80-84)
I20260812 06:17:48.038810 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000018 (ops 85-89)
I20260812 06:17:48.038879 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000019 (ops 90-94)
I20260812 06:17:48.038911 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000020 (ops 95-99)
I20260812 06:17:48.038930 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000021 (ops 100-104)
I20260812 06:17:48.038949 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000022 (ops 105-109)
I20260812 06:17:48.038968 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000023 (ops 110-114)
I20260812 06:17:48.039157 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000024 (ops 115-119)
I20260812 06:17:48.039204 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000025 (ops 120-124)
I20260812 06:17:48.073962 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: LogGCOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.036s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:17:48.074739 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=3.181125
I20260812 06:17:48.095815 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.021s	user 0.010s	sys 0.010s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":8451,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:48.096489 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling LogGCOp(7d82ea284af14c90a5f9bd0ce8b9366d): free 11564877 bytes of WAL
I20260812 06:17:48.096761 13147 log_reader.cc:385] T 7d82ea284af14c90a5f9bd0ce8b9366d: removed 1 log segments from log reader
I20260812 06:17:48.096843 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000026 (ops 125-128)
I20260812 06:17:48.100247 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: LogGCOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:48.101141 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling UndoDeltaBlockGCOp(7d82ea284af14c90a5f9bd0ce8b9366d): 463 bytes on disk
I20260812 06:17:48.101858 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: UndoDeltaBlockGCOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:17:48.102496 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:48.117357 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.015s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5290,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:48.119207 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:48.351619 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.232s	user 0.166s	sys 0.065s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795398,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1276,"lbm_read_time_us":18509,"lbm_reads_lt_1ms":674,"lbm_write_time_us":45636,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":44416,"thread_start_us":89,"threads_started":1,"update_count":3000}
I20260812 06:17:48.352708 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=14.095187
I20260812 06:17:48.416000 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.063s	user 0.026s	sys 0.036s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":31840,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:17:48.416879 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:48.434986 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.018s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5020,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.435679 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:48.618768 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.183s	user 0.127s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692757,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1001,"lbm_read_time_us":12889,"lbm_reads_lt_1ms":564,"lbm_write_time_us":35617,"lbm_writes_lt_1ms":543,"mutex_wait_us":571,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:48.620883 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=12.110812
I20260812 06:17:48.671947 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.051s	user 0.038s	sys 0.012s Metrics: {"bytes_written":13538207,"delete_count":0,"lbm_write_time_us":22610,"lbm_writes_lt_1ms":333,"reinsert_count":0,"update_count":1650}
I20260812 06:17:48.672912 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.196750
I20260812 06:17:48.687506 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.014s	user 0.002s	sys 0.008s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":4037,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:17:48.688261 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:48.867040 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.179s	user 0.131s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590310,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1636,"lbm_read_time_us":11821,"lbm_reads_lt_1ms":464,"lbm_write_time_us":30533,"lbm_writes_lt_1ms":443,"mutex_wait_us":407,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:48.867591 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=11.118625
I20260812 06:17:48.924906 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.057s	user 0.039s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":22884,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:48.925782 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:48.953366 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.027s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7583,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.954365 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:48.982336 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.028s	user 0.013s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5969,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:48.983078 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:49.223369 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.240s	user 0.160s	sys 0.068s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692869,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1096,"lbm_read_time_us":17377,"lbm_reads_lt_1ms":573,"lbm_write_time_us":38742,"lbm_writes_lt_1ms":543,"mutex_wait_us":419,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:49.224049 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=11.118625
I20260812 06:17:49.276247 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.052s	user 0.042s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":23775,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:49.276994 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:49.297153 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.020s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4992,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:49.298200 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:49.461613 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.163s	user 0.123s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590339,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":234,"lbm_read_time_us":9630,"lbm_reads_lt_1ms":464,"lbm_write_time_us":34338,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:49.462419 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=10.126437
I20260812 06:17:49.509438 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.047s	user 0.018s	sys 0.021s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18607,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:49.510852 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:49.525269 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.014s	user 0.006s	sys 0.005s 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:17:49.526151 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:49.672398 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.146s	user 0.116s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590349,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1705,"lbm_read_time_us":11389,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24912,"lbm_writes_lt_1ms":443,"mutex_wait_us":450,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:17:49.673089 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=10.126437
I20260812 06:17:49.732364 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.059s	user 0.030s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22294,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:49.733387 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:49.748363 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.015s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5459,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.749220 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushMRSOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:49.782696 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushMRSOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.033s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":287,"dirs.run_wall_time_us":1973,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2285,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:49.783726 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling LogGCOp(7d82ea284af14c90a5f9bd0ce8b9366d): free 108535638 bytes of WAL
I20260812 06:17:49.784062 13147 log_reader.cc:385] T 7d82ea284af14c90a5f9bd0ce8b9366d: removed 11 log segments from log reader
I20260812 06:17:49.784128 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000027 (ops 129-133)
I20260812 06:17:49.784217 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000028 (ops 134-138)
I20260812 06:17:49.784266 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000029 (ops 139-142)
I20260812 06:17:49.784292 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000030 (ops 143-147)
I20260812 06:17:49.784366 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000031 (ops 148-152)
I20260812 06:17:49.784411 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000032 (ops 153-157)
I20260812 06:17:49.784438 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000033 (ops 158-162)
I20260812 06:17:49.784464 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000034 (ops 163-166)
I20260812 06:17:49.784498 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000035 (ops 167-171)
I20260812 06:17:49.784528 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000036 (ops 172-176)
I20260812 06:17:49.784564 13147 log.cc:1079] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/7d82ea284af14c90a5f9bd0ce8b9366d/wal-000000037 (ops 177-181)
I20260812 06:17:49.813179 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: LogGCOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:49.813735 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:49.835750 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.022s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4637,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.836381 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling UndoDeltaBlockGCOp(7d82ea284af14c90a5f9bd0ce8b9366d): 448 bytes on disk
I20260812 06:17:49.836921 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: UndoDeltaBlockGCOp(7d82ea284af14c90a5f9bd0ce8b9366d) 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:17:49.837498 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:49.848865 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4330,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.849408 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:50.081410 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.232s	user 0.179s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795409,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2660,"lbm_read_time_us":13596,"lbm_reads_lt_1ms":674,"lbm_write_time_us":43439,"lbm_writes_lt_1ms":643,"mutex_wait_us":563,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":26752,"thread_start_us":124,"threads_started":1,"update_count":3000}
I20260812 06:17:50.082301 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=14.095187
I20260812 06:17:50.151580 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.069s	user 0.034s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":29683,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.152217 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=2.188937
I20260812 06:17:50.169515 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5015,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.170476 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:50.313037 13025 heavy-update-compaction-itest.cc:229] Time spent updating: real 6.175s	user 2.312s	sys 0.155s
I20260812 06:17:50.359848 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.189s	user 0.141s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":14323,"lbm_reads_lt_1ms":560,"lbm_write_time_us":35430,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:17:50.360447 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=10.126437
I20260812 06:17:50.393690 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: FlushDeltaMemStoresOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.033s	user 0.013s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14825,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:50.394407 13218 maintenance_manager.cc:419] P 49da6b1811ae4f12a0870e939391b26e: Scheduling MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d): perf score=1.000000
I20260812 06:17:50.400768 13025 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.087s	user 0.002s	sys 0.000s
I20260812 06:17:50.401507 13025 tablet_server.cc:179] TabletServer@127.12.184.65:0 shutting down...
I20260812 06:17:50.511127 13147 maintenance_manager.cc:643] P 49da6b1811ae4f12a0870e939391b26e: MajorDeltaCompactionOp(7d82ea284af14c90a5f9bd0ce8b9366d) complete. Timing: real 0.116s	user 0.093s	sys 0.023s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16487816,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":379,"lbm_read_time_us":10157,"lbm_reads_lt_1ms":367,"lbm_write_time_us":19844,"lbm_writes_lt_1ms":343,"mutex_wait_us":1,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":1500}
I20260812 06:17:50.512223 13025 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:50.512692 13025 tablet_replica.cc:333] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e: stopping tablet replica
I20260812 06:17:50.512941 13025 raft_consensus.cc:2243] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:50.513192 13025 raft_consensus.cc:2272] T 7d82ea284af14c90a5f9bd0ce8b9366d P 49da6b1811ae4f12a0870e939391b26e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:50.530514 13025 tablet_server.cc:196] TabletServer@127.12.184.65:0 shutdown complete.
I20260812 06:17:50.545449 13025 master.cc:562] Master@127.12.184.126:46727 shutting down...
I20260812 06:17:50.550379 13025 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:50.550571 13025 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:50.550747 13025 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1bed081ac2dc4f968ef356d4dfb99687: stopping tablet replica
I20260812 06:17:50.563874 13025 master.cc:584] Master@127.12.184.126:46727 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6884 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:50.663636 13025 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.184.126:39657
I20260812 06:17:50.664045 13025 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:50.666553 13025 server_base.cc:1061] running on GCE node
W20260812 06:17:50.666538 13254 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:17:50.666540 13250 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:17:50.666972 13251 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:17:50.667237 13025 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:50.667305 13025 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:17:50.667330 13025 hybrid_clock.cc:648] HybridClock initialized: now 1786515470667329 us; error 0 us; skew 500 ppm
I20260812 06:17:50.668254 13025 webserver.cc:533] Webserver started at http://127.12.184.126:44575/ using document root <none> and password file <none>
I20260812 06:17:50.668448 13025 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:50.668519 13025 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:50.668602 13025 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:50.669035 13025 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/master-0-root/instance:
uuid: "117e81d4ea9744018946549e65f51c5a"
format_stamp: "Formatted at 2026-08-12 06:17:50 on dist-test-slave-dhph"
I20260812 06:17:50.670773 13025 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:50.672219 13261 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:17:50.672626 13025 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:17:50.672758 13025 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/master-0-root
uuid: "117e81d4ea9744018946549e65f51c5a"
format_stamp: "Formatted at 2026-08-12 06:17:50 on dist-test-slave-dhph"
I20260812 06:17:50.672878 13025 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-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:17:50.695262 13025 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:50.695737 13025 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:50.701040 13025 rpc_server.cc:307] RPC server started. Bound to: 127.12.184.126:39657
I20260812 06:17:50.703066 13323 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.184.126:39657 every 8 connection(s)
I20260812 06:17:50.704322 13325 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:17:50.718066 13325 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a: Bootstrap starting.
I20260812 06:17:50.719273 13325 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:50.720515 13325 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a: No bootstrap required, opened a new log
I20260812 06:17:50.721069 13325 raft_consensus.cc:359] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "117e81d4ea9744018946549e65f51c5a" member_type: VOTER }
I20260812 06:17:50.721169 13325 raft_consensus.cc:385] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:50.721192 13325 raft_consensus.cc:740] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 117e81d4ea9744018946549e65f51c5a, State: Initialized, Role: FOLLOWER
I20260812 06:17:50.721369 13325 consensus_queue.cc:260] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [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: "117e81d4ea9744018946549e65f51c5a" member_type: VOTER }
I20260812 06:17:50.721465 13325 raft_consensus.cc:399] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:50.721490 13325 raft_consensus.cc:493] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:50.721573 13325 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:50.722457 13325 raft_consensus.cc:515] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "117e81d4ea9744018946549e65f51c5a" member_type: VOTER }
I20260812 06:17:50.722633 13325 leader_election.cc:304] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [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: 117e81d4ea9744018946549e65f51c5a; no voters: 
I20260812 06:17:50.722880 13325 leader_election.cc:290] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:50.723057 13329 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:50.723281 13329 raft_consensus.cc:697] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [term 1 LEADER]: Becoming Leader. State: Replica: 117e81d4ea9744018946549e65f51c5a, State: Running, Role: LEADER
I20260812 06:17:50.723371 13325 sys_catalog.cc:565] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:50.723443 13329 consensus_queue.cc:237] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [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: "117e81d4ea9744018946549e65f51c5a" member_type: VOTER }
I20260812 06:17:50.723937 13330 sys_catalog.cc:455] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "117e81d4ea9744018946549e65f51c5a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "117e81d4ea9744018946549e65f51c5a" member_type: VOTER } }
I20260812 06:17:50.724040 13330 sys_catalog.cc:458] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:50.723990 13331 sys_catalog.cc:455] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 117e81d4ea9744018946549e65f51c5a. Latest consensus state: current_term: 1 leader_uuid: "117e81d4ea9744018946549e65f51c5a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "117e81d4ea9744018946549e65f51c5a" member_type: VOTER } }
I20260812 06:17:50.724293 13331 sys_catalog.cc:458] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:50.724681 13335 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:50.725383 13335 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:50.725631 13025 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:50.727504 13335 catalog_manager.cc:1383] Generated new cluster ID: 8d38ed2aec6946faa1a724fad0b40007
I20260812 06:17:50.727576 13335 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:50.743278 13335 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:50.743975 13335 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:50.751945 13335 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a: Generated new TSK 0
I20260812 06:17:50.752164 13335 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:50.758342 13025 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:50.761144 13025 server_base.cc:1061] running on GCE node
W20260812 06:17:50.761170 13348 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:17:50.761302 13347 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:17:50.761170 13350 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:17:50.761585 13025 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:50.761654 13025 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:17:50.761682 13025 hybrid_clock.cc:648] HybridClock initialized: now 1786515470761680 us; error 0 us; skew 500 ppm
I20260812 06:17:50.762784 13025 webserver.cc:533] Webserver started at http://127.12.184.65:38821/ using document root <none> and password file <none>
I20260812 06:17:50.762977 13025 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:50.763052 13025 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:50.763131 13025 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:50.763578 13025 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/instance:
uuid: "b3ca6aae24394cf5b2ce0f0ef2a0f9ff"
format_stamp: "Formatted at 2026-08-12 06:17:50 on dist-test-slave-dhph"
I20260812 06:17:50.765283 13025 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:50.766700 13359 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:17:50.767140 13025 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:50.767407 13025 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root
uuid: "b3ca6aae24394cf5b2ce0f0ef2a0f9ff"
format_stamp: "Formatted at 2026-08-12 06:17:50 on dist-test-slave-dhph"
I20260812 06:17:50.767514 13025 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-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:17:50.779500 13025 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:50.779980 13025 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:50.780326 13025 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:50.780843 13025 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:50.780905 13025 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:50.780969 13025 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:50.781003 13025 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:50.786350 13025 rpc_server.cc:307] RPC server started. Bound to: 127.12.184.65:33773
I20260812 06:17:50.786399 13434 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.184.65:33773 every 8 connection(s)
I20260812 06:17:50.792570 13438 heartbeater.cc:344] Connected to a master server at 127.12.184.126:39657
I20260812 06:17:50.792718 13438 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:50.793015 13438 heartbeater.cc:507] Master 127.12.184.126:39657 requested a full tablet report, sending...
I20260812 06:17:50.793843 13282 ts_manager.cc:194] Registered new tserver with Master: b3ca6aae24394cf5b2ce0f0ef2a0f9ff (127.12.184.65:33773)
I20260812 06:17:50.793870 13025 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006962503s
I20260812 06:17:50.795212 13282 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49370
I20260812 06:17:50.803593 13282 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49380:
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:17:50.814266 13394 tablet_service.cc:1511] Processing CreateTablet for tablet 297223da677b4428b86103ceb2654136 (DEFAULT_TABLE table=heavy-update-compaction-test [id=45cac2e98662477eb306e542c6882165]), partition=
I20260812 06:17:50.814702 13394 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 297223da677b4428b86103ceb2654136. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:50.817677 13453 tablet_bootstrap.cc:492] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Bootstrap starting.
I20260812 06:17:50.818775 13453 tablet_bootstrap.cc:654] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:50.820356 13453 tablet_bootstrap.cc:492] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: No bootstrap required, opened a new log
I20260812 06:17:50.820475 13453 ts_tablet_manager.cc:1403] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:17:50.821107 13453 raft_consensus.cc:359] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3ca6aae24394cf5b2ce0f0ef2a0f9ff" member_type: VOTER last_known_addr { host: "127.12.184.65" port: 33773 } }
I20260812 06:17:50.821396 13453 raft_consensus.cc:385] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:50.821544 13453 raft_consensus.cc:740] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b3ca6aae24394cf5b2ce0f0ef2a0f9ff, State: Initialized, Role: FOLLOWER
I20260812 06:17:50.821763 13453 consensus_queue.cc:260] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff [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: "b3ca6aae24394cf5b2ce0f0ef2a0f9ff" member_type: VOTER last_known_addr { host: "127.12.184.65" port: 33773 } }
I20260812 06:17:50.821892 13453 raft_consensus.cc:399] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:50.821938 13453 raft_consensus.cc:493] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:50.821993 13453 raft_consensus.cc:3060] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:50.822963 13453 raft_consensus.cc:515] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3ca6aae24394cf5b2ce0f0ef2a0f9ff" member_type: VOTER last_known_addr { host: "127.12.184.65" port: 33773 } }
I20260812 06:17:50.823244 13453 leader_election.cc:304] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff [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: b3ca6aae24394cf5b2ce0f0ef2a0f9ff; no voters: 
I20260812 06:17:50.823590 13453 leader_election.cc:290] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:50.823729 13456 raft_consensus.cc:2804] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:50.824090 13453 ts_tablet_manager.cc:1434] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Time spent starting tablet: real 0.004s	user 0.003s	sys 0.001s
I20260812 06:17:50.824149 13438 heartbeater.cc:499] Master 127.12.184.126:39657 was elected leader, sending a full tablet report...
I20260812 06:17:50.824095 13456 raft_consensus.cc:697] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff [term 1 LEADER]: Becoming Leader. State: Replica: b3ca6aae24394cf5b2ce0f0ef2a0f9ff, State: Running, Role: LEADER
I20260812 06:17:50.824335 13456 consensus_queue.cc:237] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff [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: "b3ca6aae24394cf5b2ce0f0ef2a0f9ff" member_type: VOTER last_known_addr { host: "127.12.184.65" port: 33773 } }
I20260812 06:17:50.825747 13282 catalog_manager.cc:5719] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff reported cstate change: term changed from 0 to 1, leader changed from <none> to b3ca6aae24394cf5b2ce0f0ef2a0f9ff (127.12.184.65). New cstate: current_term: 1 leader_uuid: "b3ca6aae24394cf5b2ce0f0ef2a0f9ff" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3ca6aae24394cf5b2ce0f0ef2a0f9ff" member_type: VOTER last_known_addr { host: "127.12.184.65" port: 33773 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:50.892778 13025 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.021s	sys 0.004s
I20260812 06:17:51.037509 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushMRSOp(297223da677b4428b86103ceb2654136): perf score=15.086190
I20260812 06:17:51.194125 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushMRSOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.156s	user 0.124s	sys 0.024s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":882,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39694,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"update_count":1500}
I20260812 06:17:51.194958 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling LogGCOp(297223da677b4428b86103ceb2654136): free 11976772 bytes of WAL
I20260812 06:17:51.195207 13364 log_reader.cc:385] T 297223da677b4428b86103ceb2654136: removed 1 log segments from log reader
I20260812 06:17:51.195291 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000001 (ops 1-6)
I20260812 06:17:51.198146 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: LogGCOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:51.198634 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling UndoDeltaBlockGCOp(297223da677b4428b86103ceb2654136): 12308958 bytes on disk
I20260812 06:17:51.199179 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: UndoDeltaBlockGCOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:17:51.199633 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:51.216914 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5614,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.217432 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:51.360754 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.143s	user 0.086s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":554,"lbm_read_time_us":9454,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26501,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11904,"thread_start_us":360,"threads_started":5,"update_count":2000}
I20260812 06:17:51.362250 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=10.126437
I20260812 06:17:51.400867 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.038s	user 0.031s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15940,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:51.401422 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:51.420156 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.019s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7656,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.421340 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:51.570868 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.149s	user 0.104s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":409,"lbm_read_time_us":8949,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28108,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:17:51.571602 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=11.118625
I20260812 06:17:51.619432 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.048s	user 0.023s	sys 0.024s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":16901,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:51.620067 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:51.637755 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.017s	user 0.001s	sys 0.013s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":6405,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:17:51.638250 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:51.823868 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.185s	user 0.111s	sys 0.064s Metrics: {"cfile_cache_miss":435,"cfile_cache_miss_bytes":20754384,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":462,"lbm_read_time_us":10896,"lbm_reads_lt_1ms":467,"lbm_write_time_us":29746,"lbm_writes_lt_1ms":446,"mutex_wait_us":53,"peak_mem_usage":50812433,"reinsert_count":0,"spinlock_wait_cycles":76416,"update_count":2015}
I20260812 06:17:51.824635 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=14.095187
I20260812 06:17:51.884996 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.060s	user 0.034s	sys 0.020s Metrics: {"bytes_written":16286836,"delete_count":0,"lbm_write_time_us":25189,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":1985}
I20260812 06:17:51.885510 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:51.898773 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4754,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.899333 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:52.104321 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.205s	user 0.169s	sys 0.028s Metrics: {"cfile_cache_miss":529,"cfile_cache_miss_bytes":24610657,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":452,"lbm_read_time_us":13657,"lbm_reads_lt_1ms":569,"lbm_write_time_us":39081,"lbm_writes_lt_1ms":540,"peak_mem_usage":61952411,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2485}
I20260812 06:17:52.105082 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=14.095187
I20260812 06:17:52.161136 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.056s	user 0.027s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23791,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.161823 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:52.173712 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.012s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4576,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.174424 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:52.323325 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.149s	user 0.108s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":152,"lbm_read_time_us":10995,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29982,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:17:52.324051 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=10.126437
I20260812 06:17:52.362159 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.038s	user 0.015s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16522,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:52.362757 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:52.383154 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.020s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":9524,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.383720 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:52.507892 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.124s	user 0.094s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":251,"lbm_read_time_us":8604,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24971,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:17:52.508665 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=10.126437
I20260812 06:17:52.546947 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.038s	user 0.013s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16461,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:52.547641 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushMRSOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:52.586710 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushMRSOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.039s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":98,"dirs.run_cpu_time_us":380,"dirs.run_wall_time_us":1847,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1961,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:52.587574 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=3.181125
I20260812 06:17:52.610253 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.022s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7328,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:52.611069 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling LogGCOp(297223da677b4428b86103ceb2654136): free 121006430 bytes of WAL
I20260812 06:17:52.611339 13364 log_reader.cc:385] T 297223da677b4428b86103ceb2654136: removed 12 log segments from log reader
I20260812 06:17:52.611493 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000002 (ops 7-11)
I20260812 06:17:52.611560 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000003 (ops 12-16)
I20260812 06:17:52.611601 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000004 (ops 17-20)
I20260812 06:17:52.611624 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000005 (ops 21-25)
I20260812 06:17:52.611646 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000006 (ops 26-30)
I20260812 06:17:52.611670 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000007 (ops 31-35)
I20260812 06:17:52.611693 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000008 (ops 36-40)
I20260812 06:17:52.611728 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000009 (ops 41-45)
I20260812 06:17:52.611843 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000010 (ops 46-50)
I20260812 06:17:52.611889 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000011 (ops 51-55)
I20260812 06:17:52.611923 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000012 (ops 56-60)
I20260812 06:17:52.611953 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000013 (ops 61-65)
I20260812 06:17:52.644552 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: LogGCOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.033s	user 0.008s	sys 0.024s Metrics: {}
I20260812 06:17:52.645037 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling UndoDeltaBlockGCOp(297223da677b4428b86103ceb2654136): 473 bytes on disk
I20260812 06:17:52.645558 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: UndoDeltaBlockGCOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:17:52.646163 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:52.673336 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.027s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5031,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:52.674111 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling LogGCOp(297223da677b4428b86103ceb2654136): free 12017932 bytes of WAL
I20260812 06:17:52.674546 13364 log_reader.cc:385] T 297223da677b4428b86103ceb2654136: removed 1 log segments from log reader
I20260812 06:17:52.674672 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000014 (ops 66-70)
I20260812 06:17:52.678324 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: LogGCOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:52.678864 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:52.694255 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5874,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.695006 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:52.896579 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.201s	user 0.139s	sys 0.058s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836364,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":713,"lbm_read_time_us":13995,"lbm_reads_lt_1ms":674,"lbm_write_time_us":39599,"lbm_writes_lt_1ms":643,"mutex_wait_us":365,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":29952,"thread_start_us":93,"threads_started":1,"update_count":3000}
I20260812 06:17:52.897464 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=14.095187
I20260812 06:17:52.966425 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.069s	user 0.029s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26732,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.967061 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=3.181125
I20260812 06:17:52.985249 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.018s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":5810,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:52.985775 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:52.999902 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5141,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:53.000538 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:53.190642 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.190s	user 0.159s	sys 0.027s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836243,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1533,"lbm_read_time_us":14398,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38605,"lbm_writes_lt_1ms":643,"mutex_wait_us":495,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:17:53.191315 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=14.095187
I20260812 06:17:53.250695 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.059s	user 0.034s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23868,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:53.251471 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:53.269115 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6617,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.269937 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:53.440881 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.171s	user 0.122s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":240,"lbm_read_time_us":11715,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33021,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:17:53.441705 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=10.126437
I20260812 06:17:53.489722 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.048s	user 0.032s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":22069,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:53.490289 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:53.502480 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4880,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.503044 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:53.672399 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.169s	user 0.096s	sys 0.071s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":839,"lbm_read_time_us":11614,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28998,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19584,"update_count":2000}
I20260812 06:17:53.673312 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=10.126437
I20260812 06:17:53.730288 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.056s	user 0.044s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":23681,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:53.730929 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:53.745193 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5294,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.746115 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:53.923079 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.177s	user 0.120s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":405,"lbm_read_time_us":11546,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29306,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19200,"update_count":2000}
I20260812 06:17:53.924080 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=10.126437
I20260812 06:17:53.984912 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.061s	user 0.039s	sys 0.012s Metrics: {"bytes_written":12307501,"delete_count":0,"lbm_write_time_us":22754,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:53.985548 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:53.999847 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5370,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.000456 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:54.170053 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.169s	user 0.124s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631323,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1053,"lbm_read_time_us":11017,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32049,"lbm_writes_lt_1ms":443,"mutex_wait_us":265,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.170929 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=10.126437
I20260812 06:17:54.236749 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.066s	user 0.032s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21988,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.237399 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:54.256880 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.019s	user 0.012s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6956,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.257872 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushMRSOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:54.299396 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushMRSOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.041s	user 0.033s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":95,"dirs.run_cpu_time_us":480,"dirs.run_wall_time_us":2171,"drs_written":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2412,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:54.300302 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling LogGCOp(297223da677b4428b86103ceb2654136): free 112692366 bytes of WAL
I20260812 06:17:54.300590 13364 log_reader.cc:385] T 297223da677b4428b86103ceb2654136: removed 11 log segments from log reader
I20260812 06:17:54.300675 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000015 (ops 71-75)
I20260812 06:17:54.300738 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000016 (ops 76-80)
I20260812 06:17:54.300805 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000017 (ops 81-85)
I20260812 06:17:54.300855 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000018 (ops 86-90)
I20260812 06:17:54.300900 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000019 (ops 91-95)
I20260812 06:17:54.300945 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000020 (ops 96-100)
I20260812 06:17:54.300987 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000021 (ops 101-105)
I20260812 06:17:54.301031 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000022 (ops 106-110)
I20260812 06:17:54.301075 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000023 (ops 111-115)
I20260812 06:17:54.301120 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000024 (ops 116-120)
I20260812 06:17:54.301155 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000025 (ops 121-125)
I20260812 06:17:54.328889 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: LogGCOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:54.329401 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling UndoDeltaBlockGCOp(297223da677b4428b86103ceb2654136): 462 bytes on disk
I20260812 06:17:54.329938 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: UndoDeltaBlockGCOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:17:54.330499 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:54.351294 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.021s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4784,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.351807 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:54.366048 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.014s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4935,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.367311 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:54.569667 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.202s	user 0.128s	sys 0.073s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836374,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1016,"lbm_read_time_us":16115,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40775,"lbm_writes_lt_1ms":643,"mutex_wait_us":1122,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":222336,"thread_start_us":87,"threads_started":1,"update_count":3000}
I20260812 06:17:54.571046 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=14.095187
I20260812 06:17:54.630651 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.059s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23270,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.631235 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:54.644443 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4878,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.645036 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:54.832250 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.187s	user 0.128s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":5963,"lbm_read_time_us":11966,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33490,"lbm_writes_lt_1ms":543,"mutex_wait_us":4636,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24960,"update_count":2500}
I20260812 06:17:54.832851 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=14.095187
I20260812 06:17:54.897161 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.064s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24475,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.897740 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:54.910481 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4386,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.911108 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:55.118490 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.207s	user 0.135s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1014,"lbm_read_time_us":15185,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34135,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:17:55.119500 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=14.095187
I20260812 06:17:55.178927 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.059s	user 0.039s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24624,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.179690 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:55.350862 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.171s	user 0.122s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631191,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":3617,"lbm_read_time_us":9709,"lbm_reads_lt_1ms":463,"lbm_write_time_us":28693,"lbm_writes_lt_1ms":443,"mutex_wait_us":2642,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:17:55.351929 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=14.095187
I20260812 06:17:55.410368 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.058s	user 0.036s	sys 0.016s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":24495,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.411074 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:55.422093 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4132,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.422847 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:55.609357 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.186s	user 0.134s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733721,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":317,"lbm_read_time_us":10733,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30844,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20736,"update_count":2500}
I20260812 06:17:55.610126 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=14.095187
I20260812 06:17:55.669965 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.060s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24941,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.671015 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:55.686753 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.015s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5178,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.687328 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:55.855894 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.168s	user 0.138s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":224,"lbm_read_time_us":10408,"lbm_reads_lt_1ms":568,"lbm_write_time_us":36254,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2500}
I20260812 06:17:55.856690 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=11.118625
I20260812 06:17:55.909160 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.052s	user 0.030s	sys 0.020s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":22608,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:55.909873 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:55.941166 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.031s	user 0.012s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7377,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:55.941784 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:55.955693 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4866,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.956743 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushMRSOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:56.001264 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushMRSOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.044s	user 0.038s	sys 0.003s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":264,"dirs.run_wall_time_us":1576,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3562,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:56.002091 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling LogGCOp(297223da677b4428b86103ceb2654136): free 133024632 bytes of WAL
I20260812 06:17:56.002372 13364 log_reader.cc:385] T 297223da677b4428b86103ceb2654136: removed 13 log segments from log reader
I20260812 06:17:56.002427 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000026 (ops 126-130)
I20260812 06:17:56.002465 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000027 (ops 131-135)
I20260812 06:17:56.002498 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000028 (ops 136-140)
I20260812 06:17:56.002528 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000029 (ops 141-145)
I20260812 06:17:56.002556 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000030 (ops 146-150)
I20260812 06:17:56.002609 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000031 (ops 151-154)
I20260812 06:17:56.002641 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000032 (ops 155-159)
I20260812 06:17:56.002665 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000033 (ops 160-164)
I20260812 06:17:56.002699 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000034 (ops 165-169)
I20260812 06:17:56.002733 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000035 (ops 170-174)
I20260812 06:17:56.002765 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000036 (ops 175-179)
I20260812 06:17:56.002794 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000037 (ops 180-184)
I20260812 06:17:56.002820 13364 log.cc:1079] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Deleting log segment in path: /tmp/dist-test-tasknvtfvP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515463768328-13025-0/minicluster-data/ts-0-root/wals/297223da677b4428b86103ceb2654136/wal-000000038 (ops 185-189)
I20260812 06:17:56.036808 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: LogGCOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.034s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:56.037287 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=6.157687
I20260812 06:17:56.068064 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.031s	user 0.018s	sys 0.011s Metrics: {"bytes_written":7507667,"delete_count":0,"lbm_write_time_us":8012,"lbm_writes_lt_1ms":186,"reinsert_count":0,"update_count":915}
I20260812 06:17:56.068650 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling UndoDeltaBlockGCOp(297223da677b4428b86103ceb2654136): 483 bytes on disk
I20260812 06:17:56.069185 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: UndoDeltaBlockGCOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4}
I20260812 06:17:56.069712 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:56.318884 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.249s	user 0.165s	sys 0.079s Metrics: {"cfile_cache_miss":717,"cfile_cache_miss_bytes":32241369,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":621,"lbm_read_time_us":18522,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":752,"lbm_write_time_us":39651,"lbm_writes_lt_1ms":726,"mutex_wait_us":89,"peak_mem_usage":85190681,"reinsert_count":0,"spinlock_wait_cycles":98048,"thread_start_us":104,"threads_started":1,"update_count":3415}
I20260812 06:17:56.319712 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=15.087375
I20260812 06:17:56.338984 13025 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.446s	user 2.066s	sys 0.147s
I20260812 06:17:56.382828 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.063s	user 0.031s	sys 0.031s Metrics: {"bytes_written":17517561,"delete_count":0,"lbm_write_time_us":27960,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":429,"reinsert_count":0,"update_count":2135}
I20260812 06:17:56.383446 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136): perf score=2.188937
I20260812 06:17:56.391497 13025 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.052s	user 0.002s	sys 0.000s
I20260812 06:17:56.392035 13025 tablet_server.cc:179] TabletServer@127.12.184.65:0 shutting down...
I20260812 06:17:56.395426 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: FlushDeltaMemStoresOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4029,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:56.396005 13439 maintenance_manager.cc:419] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: Scheduling MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136): perf score=1.000000
I20260812 06:17:56.543315 13364 maintenance_manager.cc:643] P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: MajorDeltaCompactionOp(297223da677b4428b86103ceb2654136) complete. Timing: real 0.147s	user 0.115s	sys 0.032s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4221425,"cfile_cache_miss":519,"cfile_cache_miss_bytes":21209704,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":415,"lbm_read_time_us":8539,"lbm_reads_lt_1ms":535,"lbm_write_time_us":25427,"lbm_writes_lt_1ms":560,"mutex_wait_us":44,"peak_mem_usage":64853879,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2585}
I20260812 06:17:56.544124 13025 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:56.544394 13025 tablet_replica.cc:333] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff: stopping tablet replica
I20260812 06:17:56.544564 13025 raft_consensus.cc:2243] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:56.544754 13025 raft_consensus.cc:2272] T 297223da677b4428b86103ceb2654136 P b3ca6aae24394cf5b2ce0f0ef2a0f9ff [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:56.549098 13025 tablet_server.cc:196] TabletServer@127.12.184.65:0 shutdown complete.
I20260812 06:17:56.591440 13025 master.cc:562] Master@127.12.184.126:39657 shutting down...
I20260812 06:17:56.595572 13025 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:56.595827 13025 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:56.595969 13025 tablet_replica.cc:333] T 00000000000000000000000000000000 P 117e81d4ea9744018946549e65f51c5a: stopping tablet replica
I20260812 06:17:56.608965 13025 master.cc:584] Master@127.12.184.126:39657 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6044 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12929 ms total)

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