[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:20.370038 29127 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.113.254:42005
I20260812 06:20:20.370980 29127 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:20.371575 29127 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:20.378052 29139 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:20.378098 29136 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:20.378155 29127 server_base.cc:1061] running on GCE node
W20260812 06:20:20.378391 29135 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:20.378912 29127 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:20.379002 29127 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:20.379055 29127 hybrid_clock.cc:648] HybridClock initialized: now 1786515620379052 us; error 0 us; skew 500 ppm
I20260812 06:20:20.380803 29127 webserver.cc:533] Webserver started at http://127.28.113.254:45937/ using document root <none> and password file <none>
I20260812 06:20:20.381330 29127 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:20.381386 29127 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:20.381649 29127 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:20.383332 29127 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/master-0-root/instance:
uuid: "1aff3d76f4134c028c95b89f059270aa"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-92m1"
I20260812 06:20:20.386603 29127 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:20.388623 29149 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:20.389565 29127 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:20.389663 29127 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/master-0-root
uuid: "1aff3d76f4134c028c95b89f059270aa"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-92m1"
I20260812 06:20:20.389783 29127 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:20.403674 29127 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:20.404247 29127 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:20.404429 29127 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:20.412276 29127 rpc_server.cc:307] RPC server started. Bound to: 127.28.113.254:42005
I20260812 06:20:20.412297 29249 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.113.254:42005 every 8 connection(s)
I20260812 06:20:20.414412 29250 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:20.419518 29250 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa: Bootstrap starting.
I20260812 06:20:20.421694 29250 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:20.422537 29250 log.cc:826] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:20.424111 29250 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa: No bootstrap required, opened a new log
I20260812 06:20:20.426682 29250 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1aff3d76f4134c028c95b89f059270aa" member_type: VOTER }
I20260812 06:20:20.426828 29250 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:20.426942 29250 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1aff3d76f4134c028c95b89f059270aa, State: Initialized, Role: FOLLOWER
I20260812 06:20:20.427506 29250 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [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: "1aff3d76f4134c028c95b89f059270aa" member_type: VOTER }
I20260812 06:20:20.427670 29250 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:20.427737 29250 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:20.427892 29250 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:20.428612 29250 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1aff3d76f4134c028c95b89f059270aa" member_type: VOTER }
I20260812 06:20:20.429015 29250 leader_election.cc:304] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [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: 1aff3d76f4134c028c95b89f059270aa; no voters: 
I20260812 06:20:20.429325 29250 leader_election.cc:290] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:20.429453 29255 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:20.429721 29255 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [term 1 LEADER]: Becoming Leader. State: Replica: 1aff3d76f4134c028c95b89f059270aa, State: Running, Role: LEADER
I20260812 06:20:20.430138 29255 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [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: "1aff3d76f4134c028c95b89f059270aa" member_type: VOTER }
I20260812 06:20:20.430256 29250 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:20.432000 29257 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1aff3d76f4134c028c95b89f059270aa. Latest consensus state: current_term: 1 leader_uuid: "1aff3d76f4134c028c95b89f059270aa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1aff3d76f4134c028c95b89f059270aa" member_type: VOTER } }
I20260812 06:20:20.432029 29256 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1aff3d76f4134c028c95b89f059270aa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1aff3d76f4134c028c95b89f059270aa" member_type: VOTER } }
I20260812 06:20:20.432139 29257 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:20.432196 29256 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:20.432489 29271 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:20.432497 29127 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:20.434983 29271 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:20.439857 29271 catalog_manager.cc:1383] Generated new cluster ID: 2263425082924a0781a710df22effaec
I20260812 06:20:20.439939 29271 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:20.463248 29271 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:20.464144 29271 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:20.480891 29271 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa: Generated new TSK 0
I20260812 06:20:20.481541 29271 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:20.497306 29127 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:20.500036 29283 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:20.500128 29281 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:20.500036 29279 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:20.500450 29127 server_base.cc:1061] running on GCE node
I20260812 06:20:20.500641 29127 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:20.500681 29127 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:20.500697 29127 hybrid_clock.cc:648] HybridClock initialized: now 1786515620500698 us; error 0 us; skew 500 ppm
I20260812 06:20:20.501626 29127 webserver.cc:533] Webserver started at http://127.28.113.193:34053/ using document root <none> and password file <none>
I20260812 06:20:20.501808 29127 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:20.501857 29127 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:20.501955 29127 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:20.502358 29127 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/instance:
uuid: "9fc361ee3a5a40bcb81530dfc22080a2"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-92m1"
I20260812 06:20:20.504001 29127 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:20.504985 29294 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:20.505242 29127 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:20.505333 29127 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root
uuid: "9fc361ee3a5a40bcb81530dfc22080a2"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-92m1"
I20260812 06:20:20.505419 29127 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:20.516110 29127 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:20.516522 29127 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:20.517014 29127 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:20.517859 29127 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:20.517931 29127 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:20.518013 29127 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:20.518064 29127 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:20.525254 29127 rpc_server.cc:307] RPC server started. Bound to: 127.28.113.193:39263
I20260812 06:20:20.525300 29402 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.113.193:39263 every 8 connection(s)
I20260812 06:20:20.535418 29405 heartbeater.cc:344] Connected to a master server at 127.28.113.254:42005
I20260812 06:20:20.535665 29405 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:20.536116 29405 heartbeater.cc:507] Master 127.28.113.254:42005 requested a full tablet report, sending...
I20260812 06:20:20.537556 29175 ts_manager.cc:194] Registered new tserver with Master: 9fc361ee3a5a40bcb81530dfc22080a2 (127.28.113.193:39263)
I20260812 06:20:20.538157 29127 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.0122805s
I20260812 06:20:20.538944 29175 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39618
I20260812 06:20:20.547593 29175 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39632:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:20.562008 29345 tablet_service.cc:1511] Processing CreateTablet for tablet 7873792459c349e8830ec3b11c62aebe (DEFAULT_TABLE table=heavy-update-compaction-test [id=512f11c5624b42eeadf0dfda52a79801]), partition=
I20260812 06:20:20.562450 29345 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 7873792459c349e8830ec3b11c62aebe. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:20.564926 29423 tablet_bootstrap.cc:492] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Bootstrap starting.
I20260812 06:20:20.566325 29423 tablet_bootstrap.cc:654] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:20.567683 29423 tablet_bootstrap.cc:492] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: No bootstrap required, opened a new log
I20260812 06:20:20.567791 29423 ts_tablet_manager.cc:1403] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:20.568280 29423 raft_consensus.cc:359] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9fc361ee3a5a40bcb81530dfc22080a2" member_type: VOTER last_known_addr { host: "127.28.113.193" port: 39263 } }
I20260812 06:20:20.568403 29423 raft_consensus.cc:385] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:20.568436 29423 raft_consensus.cc:740] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9fc361ee3a5a40bcb81530dfc22080a2, State: Initialized, Role: FOLLOWER
I20260812 06:20:20.568588 29423 consensus_queue.cc:260] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2 [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: "9fc361ee3a5a40bcb81530dfc22080a2" member_type: VOTER last_known_addr { host: "127.28.113.193" port: 39263 } }
I20260812 06:20:20.568698 29423 raft_consensus.cc:399] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:20.568745 29423 raft_consensus.cc:493] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:20.568804 29423 raft_consensus.cc:3060] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:20.569758 29423 raft_consensus.cc:515] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9fc361ee3a5a40bcb81530dfc22080a2" member_type: VOTER last_known_addr { host: "127.28.113.193" port: 39263 } }
I20260812 06:20:20.569909 29423 leader_election.cc:304] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2 [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: 9fc361ee3a5a40bcb81530dfc22080a2; no voters: 
I20260812 06:20:20.570127 29423 leader_election.cc:290] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:20.570248 29429 raft_consensus.cc:2804] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:20.570514 29423 ts_tablet_manager.cc:1434] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:20.570824 29405 heartbeater.cc:499] Master 127.28.113.254:42005 was elected leader, sending a full tablet report...
I20260812 06:20:20.570511 29429 raft_consensus.cc:697] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2 [term 1 LEADER]: Becoming Leader. State: Replica: 9fc361ee3a5a40bcb81530dfc22080a2, State: Running, Role: LEADER
I20260812 06:20:20.571316 29429 consensus_queue.cc:237] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2 [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: "9fc361ee3a5a40bcb81530dfc22080a2" member_type: VOTER last_known_addr { host: "127.28.113.193" port: 39263 } }
I20260812 06:20:20.573794 29175 catalog_manager.cc:5719] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2 reported cstate change: term changed from 0 to 1, leader changed from <none> to 9fc361ee3a5a40bcb81530dfc22080a2 (127.28.113.193). New cstate: current_term: 1 leader_uuid: "9fc361ee3a5a40bcb81530dfc22080a2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9fc361ee3a5a40bcb81530dfc22080a2" member_type: VOTER last_known_addr { host: "127.28.113.193" port: 39263 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:20.638332 29127 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.019s	sys 0.008s
I20260812 06:20:20.776289 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushMRSOp(7873792459c349e8830ec3b11c62aebe): perf score=19.054940
I20260812 06:20:20.983824 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushMRSOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.207s	user 0.152s	sys 0.047s Metrics: {"bytes_written":14276637,"cfile_init":1,"compiler_manager_pool.queue_time_us":191,"delete_count":0,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":270,"dirs.run_wall_time_us":936,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":50652,"lbm_writes_lt_1ms":805,"mutex_wait_us":187,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":95872,"thread_start_us":126,"threads_started":1,"update_count":1740}
I20260812 06:20:20.985140 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling LogGCOp(7873792459c349e8830ec3b11c62aebe): free 20743880 bytes of WAL
I20260812 06:20:20.985507 29300 log_reader.cc:385] T 7873792459c349e8830ec3b11c62aebe: removed 2 log segments from log reader
I20260812 06:20:20.985591 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000001 (ops 1-6)
I20260812 06:20:20.985661 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000002 (ops 7-11)
I20260812 06:20:20.991788 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: LogGCOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.006s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:20:20.992255 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling UndoDeltaBlockGCOp(7873792459c349e8830ec3b11c62aebe): 16411394 bytes on disk
I20260812 06:20:20.993062 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: UndoDeltaBlockGCOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:20:20.993530 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=4.173312
I20260812 06:20:21.019385 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.026s	user 0.025s	sys 0.000s Metrics: {"bytes_written":6235921,"delete_count":0,"lbm_write_time_us":10937,"lbm_writes_lt_1ms":155,"reinsert_count":0,"update_count":760}
I20260812 06:20:21.019956 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:21.203918 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.184s	user 0.124s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774680,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":962,"lbm_read_time_us":12776,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31433,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":310,"threads_started":5,"update_count":2500}
I20260812 06:20:21.204525 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=14.095187
I20260812 06:20:21.262614 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.058s	user 0.030s	sys 0.024s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":28466,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.263090 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:21.282557 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.019s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3937,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.283316 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:21.441555 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.158s	user 0.105s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":694,"lbm_read_time_us":11286,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28613,"lbm_writes_lt_1ms":543,"mutex_wait_us":113,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:21.442221 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=10.126437
I20260812 06:20:21.483376 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.041s	user 0.011s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17777,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.483794 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:21.495072 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4319,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.495569 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:21.629822 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.134s	user 0.115s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":359,"lbm_read_time_us":8994,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27497,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22656,"update_count":2000}
I20260812 06:20:21.630455 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=10.126437
I20260812 06:20:21.679682 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.049s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16163,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.680181 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:21.690734 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4042,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.691465 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:21.814522 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.123s	user 0.092s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":317,"lbm_read_time_us":9540,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22630,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.815099 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=10.126437
I20260812 06:20:21.860605 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.045s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17388,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.861094 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:21.873688 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4633,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.874207 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:22.005941 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.131s	user 0.091s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":204,"lbm_read_time_us":8498,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27746,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:20:22.006507 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=10.126437
I20260812 06:20:22.050227 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.044s	user 0.015s	sys 0.022s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12829,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.050853 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:22.067802 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.017s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6442,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.068394 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:22.216985 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.148s	user 0.094s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":198,"lbm_read_time_us":11637,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25411,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18176,"update_count":2000}
I20260812 06:20:22.217471 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=10.126437
I20260812 06:20:22.260433 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.043s	user 0.022s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19236,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.260972 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:22.272888 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4161,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.273540 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushMRSOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:22.306381 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushMRSOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":1188,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1536,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:22.307250 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling LogGCOp(7873792459c349e8830ec3b11c62aebe): free 124257261 bytes of WAL
I20260812 06:20:22.307515 29300 log_reader.cc:385] T 7873792459c349e8830ec3b11c62aebe: removed 12 log segments from log reader
I20260812 06:20:22.307585 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000003 (ops 12-16)
I20260812 06:20:22.307623 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000004 (ops 17-21)
I20260812 06:20:22.307657 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000005 (ops 22-26)
I20260812 06:20:22.307690 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000006 (ops 27-30)
I20260812 06:20:22.307721 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000007 (ops 31-35)
I20260812 06:20:22.307750 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000008 (ops 36-40)
I20260812 06:20:22.307780 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000009 (ops 41-45)
I20260812 06:20:22.307808 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000010 (ops 46-50)
I20260812 06:20:22.307843 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000011 (ops 51-55)
I20260812 06:20:22.307876 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000012 (ops 56-60)
I20260812 06:20:22.307906 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000013 (ops 61-65)
I20260812 06:20:22.307934 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000014 (ops 66-70)
I20260812 06:20:22.336864 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: LogGCOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:22.337353 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=5.165500
I20260812 06:20:22.362110 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.025s	user 0.011s	sys 0.011s Metrics: {"bytes_written":6728210,"delete_count":0,"lbm_write_time_us":6875,"lbm_writes_lt_1ms":167,"reinsert_count":0,"update_count":820}
I20260812 06:20:22.362665 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling UndoDeltaBlockGCOp(7873792459c349e8830ec3b11c62aebe): 472 bytes on disk
I20260812 06:20:22.363262 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: UndoDeltaBlockGCOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.363747 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:22.371018 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.007s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1477052,"delete_count":0,"lbm_write_time_us":2169,"lbm_writes_lt_1ms":39,"reinsert_count":0,"update_count":180}
I20260812 06:20:22.371731 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:22.565868 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.194s	user 0.142s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877279,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1001,"lbm_read_time_us":13395,"lbm_reads_lt_1ms":666,"lbm_write_time_us":34187,"lbm_writes_lt_1ms":643,"mutex_wait_us":325,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12928,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:20:22.566530 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=14.095187
I20260812 06:20:22.631269 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.065s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21501,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.631910 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:22.642993 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4344,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.643463 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:22.809233 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.166s	user 0.129s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":428,"lbm_read_time_us":13016,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27937,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:20:22.813050 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=11.118625
I20260812 06:20:22.846560 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.033s	user 0.025s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14009,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:22.847187 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:22.874511 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.027s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5846,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.874948 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:22.894575 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.019s	user 0.006s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4015,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.895355 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:23.087952 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.192s	user 0.144s	sys 0.037s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":157,"lbm_read_time_us":12020,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31971,"lbm_writes_lt_1ms":543,"mutex_wait_us":65,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:23.088560 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=14.095187
I20260812 06:20:23.135180 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.046s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20445,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.135767 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:23.147531 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4301,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.147992 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:23.328416 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.180s	user 0.123s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":356,"lbm_read_time_us":10048,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29258,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:20:23.329101 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=14.095187
I20260812 06:20:23.381997 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.053s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21446,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.382540 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:23.393846 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3867,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.394343 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:23.547741 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.153s	user 0.109s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":188,"lbm_read_time_us":8361,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31927,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2500}
I20260812 06:20:23.550892 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=11.118625
I20260812 06:20:23.589382 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.038s	user 0.017s	sys 0.019s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17128,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:23.590165 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:23.608503 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.018s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4726,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.609066 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:23.740775 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.132s	user 0.097s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":42,"lbm_read_time_us":8733,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25031,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:20:23.742321 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=10.126437
I20260812 06:20:23.782078 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.039s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16066,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.782634 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:23.797151 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5605,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.797650 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushMRSOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:23.827813 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushMRSOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":258,"dirs.run_wall_time_us":1202,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1590,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:23.828503 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling LogGCOp(7873792459c349e8830ec3b11c62aebe): free 121006443 bytes of WAL
I20260812 06:20:23.828738 29300 log_reader.cc:385] T 7873792459c349e8830ec3b11c62aebe: removed 12 log segments from log reader
I20260812 06:20:23.828800 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000015 (ops 71-75)
I20260812 06:20:23.828853 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000016 (ops 76-80)
I20260812 06:20:23.828908 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000017 (ops 81-84)
I20260812 06:20:23.828949 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000018 (ops 85-89)
I20260812 06:20:23.829006 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000019 (ops 90-94)
I20260812 06:20:23.829053 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000020 (ops 95-99)
I20260812 06:20:23.829093 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000021 (ops 100-104)
I20260812 06:20:23.829133 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000022 (ops 105-109)
I20260812 06:20:23.829171 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000023 (ops 110-114)
I20260812 06:20:23.829210 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000024 (ops 115-119)
I20260812 06:20:23.829250 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000025 (ops 120-124)
I20260812 06:20:23.829289 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000026 (ops 125-129)
I20260812 06:20:23.854146 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: LogGCOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.025s	user 0.004s	sys 0.018s Metrics: {}
I20260812 06:20:23.854622 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:23.870672 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.016s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.871158 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:23.882299 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4283,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.882772 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling UndoDeltaBlockGCOp(7873792459c349e8830ec3b11c62aebe): 472 bytes on disk
I20260812 06:20:23.883637 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: UndoDeltaBlockGCOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":116,"lbm_reads_lt_1ms":4}
I20260812 06:20:23.884574 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:24.055536 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.171s	user 0.114s	sys 0.054s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877340,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":444,"lbm_read_time_us":11745,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34635,"lbm_writes_lt_1ms":643,"mutex_wait_us":1,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3968,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:20:24.056589 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=14.095187
I20260812 06:20:24.109956 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.053s	user 0.013s	sys 0.037s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22891,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.110852 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:24.126535 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5734,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.127095 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:24.274222 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.147s	user 0.110s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":305,"lbm_read_time_us":10326,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27300,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":61184,"update_count":2500}
I20260812 06:20:24.274988 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=14.095187
I20260812 06:20:24.343808 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.069s	user 0.050s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":31034,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.344322 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:24.354308 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3828,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.354718 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:24.518189 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.163s	user 0.116s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":973,"lbm_read_time_us":10790,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27985,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2500}
I20260812 06:20:24.518677 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=14.095187
I20260812 06:20:24.575609 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.057s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19322,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.576140 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:24.587910 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.012s	user 0.003s	sys 0.008s 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:20:24.588377 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:24.766702 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.178s	user 0.142s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":403,"lbm_read_time_us":11926,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32505,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19456,"update_count":2500}
I20260812 06:20:24.767549 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=14.095187
I20260812 06:20:24.840098 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.072s	user 0.031s	sys 0.036s Metrics: {"bytes_written":16409911,"delete_count":0,"lbm_write_time_us":25741,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.840804 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=4.173312
I20260812 06:20:24.860881 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.020s	user 0.010s	sys 0.009s Metrics: {"bytes_written":5415440,"delete_count":0,"lbm_write_time_us":8522,"lbm_writes_lt_1ms":135,"reinsert_count":0,"update_count":660}
I20260812 06:20:24.861390 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=1.196750
I20260812 06:20:24.870350 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":3075,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:20:24.871002 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:25.096340 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.225s	user 0.138s	sys 0.087s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877200,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":574,"lbm_read_time_us":16416,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38956,"lbm_writes_lt_1ms":643,"mutex_wait_us":66,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17792,"update_count":3000}
I20260812 06:20:25.096999 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=14.095187
I20260812 06:20:25.149384 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.052s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22775,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.149910 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushMRSOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:25.187505 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushMRSOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.037s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":36,"dirs.run_cpu_time_us":263,"dirs.run_wall_time_us":1521,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1537,"lbm_writes_lt_1ms":39,"mutex_wait_us":3,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:25.188340 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=3.181125
I20260812 06:20:25.209400 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.021s	user 0.004s	sys 0.011s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7063,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:25.209908 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling LogGCOp(7873792459c349e8830ec3b11c62aebe): free 120553645 bytes of WAL
I20260812 06:20:25.210124 29300 log_reader.cc:385] T 7873792459c349e8830ec3b11c62aebe: removed 12 log segments from log reader
I20260812 06:20:25.210167 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000027 (ops 130-134)
I20260812 06:20:25.210194 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000028 (ops 135-139)
I20260812 06:20:25.210261 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000029 (ops 140-144)
I20260812 06:20:25.210305 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000030 (ops 145-149)
I20260812 06:20:25.210346 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000031 (ops 150-154)
I20260812 06:20:25.210410 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000032 (ops 155-158)
I20260812 06:20:25.210449 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000033 (ops 159-163)
I20260812 06:20:25.210491 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000034 (ops 164-168)
I20260812 06:20:25.210526 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000035 (ops 169-173)
I20260812 06:20:25.210566 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000036 (ops 174-178)
I20260812 06:20:25.210608 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000037 (ops 179-182)
I20260812 06:20:25.210646 29300 log.cc:1079] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/7873792459c349e8830ec3b11c62aebe/wal-000000038 (ops 183-187)
I20260812 06:20:25.237929 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: LogGCOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:25.238430 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling UndoDeltaBlockGCOp(7873792459c349e8830ec3b11c62aebe): 447 bytes on disk
I20260812 06:20:25.238943 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: UndoDeltaBlockGCOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.239697 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:25.258193 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.018s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4269,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:25.258673 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:25.269456 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4271,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.269912 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:25.502476 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.232s	user 0.178s	sys 0.045s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":458,"lbm_read_time_us":16744,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40797,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4736,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:20:25.503068 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=18.063937
I20260812 06:20:25.570853 29127 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.932s	user 1.822s	sys 0.162s
I20260812 06:20:25.574719 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.071s	user 0.049s	sys 0.016s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":31525,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:25.575167 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe): perf score=2.188937
I20260812 06:20:25.585945 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: FlushDeltaMemStoresOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4550,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":500}
I20260812 06:20:25.586442 29406 maintenance_manager.cc:419] P 9fc361ee3a5a40bcb81530dfc22080a2: Scheduling MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe): perf score=1.000000
I20260812 06:20:25.620314 29127 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.049s	user 0.002s	sys 0.000s
I20260812 06:20:25.620973 29127 tablet_server.cc:179] TabletServer@127.28.113.193:0 shutting down...
I20260812 06:20:25.725533 29300 maintenance_manager.cc:643] P 9fc361ee3a5a40bcb81530dfc22080a2: MajorDeltaCompactionOp(7873792459c349e8830ec3b11c62aebe) complete. Timing: real 0.139s	user 0.107s	sys 0.032s Metrics: {"cfile_cache_hit":441,"cfile_cache_hit_bytes":18051522,"cfile_cache_miss":191,"cfile_cache_miss_bytes":10825581,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":919,"lbm_read_time_us":4859,"lbm_reads_lt_1ms":223,"lbm_write_time_us":31471,"lbm_writes_lt_1ms":643,"mutex_wait_us":297,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:20:25.726307 29127 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:25.726763 29127 tablet_replica.cc:333] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2: stopping tablet replica
I20260812 06:20:25.727048 29127 raft_consensus.cc:2243] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:25.727342 29127 raft_consensus.cc:2272] T 7873792459c349e8830ec3b11c62aebe P 9fc361ee3a5a40bcb81530dfc22080a2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:25.733050 29127 tablet_server.cc:196] TabletServer@127.28.113.193:0 shutdown complete.
I20260812 06:20:25.779142 29127 master.cc:562] Master@127.28.113.254:42005 shutting down...
I20260812 06:20:25.783167 29127 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:25.783411 29127 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:25.783512 29127 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1aff3d76f4134c028c95b89f059270aa: stopping tablet replica
I20260812 06:20:25.795765 29127 master.cc:584] Master@127.28.113.254:42005 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5513 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:25.883064 29127 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.113.254:43455
I20260812 06:20:25.883479 29127 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:25.885790 29469 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:25.885848 29127 server_base.cc:1061] running on GCE node
W20260812 06:20:25.885849 29465 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:25.886054 29466 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:25.886252 29127 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:25.886296 29127 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:25.886312 29127 hybrid_clock.cc:648] HybridClock initialized: now 1786515625886311 us; error 0 us; skew 500 ppm
I20260812 06:20:25.887254 29127 webserver.cc:533] Webserver started at http://127.28.113.254:37661/ using document root <none> and password file <none>
I20260812 06:20:25.887403 29127 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:25.887444 29127 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:25.887496 29127 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:25.887831 29127 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/master-0-root/instance:
uuid: "688162c877db4cef94cccbe324200ff0"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-92m1"
I20260812 06:20:25.889278 29127 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:25.890357 29481 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.890650 29127 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:25.890743 29127 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/master-0-root
uuid: "688162c877db4cef94cccbe324200ff0"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-92m1"
I20260812 06:20:25.890826 29127 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:25.909711 29127 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:25.910109 29127 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:25.914413 29127 rpc_server.cc:307] RPC server started. Bound to: 127.28.113.254:43455
I20260812 06:20:25.915970 29564 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:25.916255 29563 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.113.254:43455 every 8 connection(s)
I20260812 06:20:25.923769 29564 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0: Bootstrap starting.
I20260812 06:20:25.924577 29564 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:25.925588 29564 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0: No bootstrap required, opened a new log
I20260812 06:20:25.925987 29564 raft_consensus.cc:359] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "688162c877db4cef94cccbe324200ff0" member_type: VOTER }
I20260812 06:20:25.926092 29564 raft_consensus.cc:385] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:25.926158 29564 raft_consensus.cc:740] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 688162c877db4cef94cccbe324200ff0, State: Initialized, Role: FOLLOWER
I20260812 06:20:25.926344 29564 consensus_queue.cc:260] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [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: "688162c877db4cef94cccbe324200ff0" member_type: VOTER }
I20260812 06:20:25.926458 29564 raft_consensus.cc:399] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:25.926503 29564 raft_consensus.cc:493] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:25.926558 29564 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:25.927311 29564 raft_consensus.cc:515] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "688162c877db4cef94cccbe324200ff0" member_type: VOTER }
I20260812 06:20:25.927459 29564 leader_election.cc:304] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [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: 688162c877db4cef94cccbe324200ff0; no voters: 
I20260812 06:20:25.927655 29564 leader_election.cc:290] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:25.927781 29570 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:25.928040 29570 raft_consensus.cc:697] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [term 1 LEADER]: Becoming Leader. State: Replica: 688162c877db4cef94cccbe324200ff0, State: Running, Role: LEADER
I20260812 06:20:25.928138 29564 sys_catalog.cc:565] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:25.928180 29570 consensus_queue.cc:237] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [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: "688162c877db4cef94cccbe324200ff0" member_type: VOTER }
I20260812 06:20:25.928694 29576 sys_catalog.cc:455] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "688162c877db4cef94cccbe324200ff0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "688162c877db4cef94cccbe324200ff0" member_type: VOTER } }
I20260812 06:20:25.928747 29577 sys_catalog.cc:455] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 688162c877db4cef94cccbe324200ff0. Latest consensus state: current_term: 1 leader_uuid: "688162c877db4cef94cccbe324200ff0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "688162c877db4cef94cccbe324200ff0" member_type: VOTER } }
I20260812 06:20:25.928879 29577 sys_catalog.cc:458] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:25.928859 29576 sys_catalog.cc:458] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:25.929359 29593 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:25.930328 29593 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:25.930562 29127 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:25.932190 29593 catalog_manager.cc:1383] Generated new cluster ID: 3dc46be787ac40a8853131a9f4129d06
I20260812 06:20:25.932250 29593 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:25.938097 29593 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:25.938599 29593 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:25.942637 29593 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0: Generated new TSK 0
I20260812 06:20:25.942775 29593 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:25.946620 29127 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:25.948658 29614 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:25.948756 29612 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:25.948809 29127 server_base.cc:1061] running on GCE node
W20260812 06:20:25.948782 29611 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:25.949186 29127 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:25.949251 29127 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:25.949276 29127 hybrid_clock.cc:648] HybridClock initialized: now 1786515625949276 us; error 0 us; skew 500 ppm
I20260812 06:20:25.950207 29127 webserver.cc:533] Webserver started at http://127.28.113.193:38981/ using document root <none> and password file <none>
I20260812 06:20:25.950376 29127 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:25.950445 29127 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:25.950539 29127 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:25.950924 29127 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/instance:
uuid: "857392f3a01c4a659799035404c5341a"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-92m1"
I20260812 06:20:25.952442 29127 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:25.953406 29626 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.953650 29127 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:25.953751 29127 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root
uuid: "857392f3a01c4a659799035404c5341a"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-92m1"
I20260812 06:20:25.953819 29127 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:25.980841 29127 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:25.981268 29127 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:25.981619 29127 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:25.982101 29127 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:25.982165 29127 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.982225 29127 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:25.982275 29127 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.986644 29127 rpc_server.cc:307] RPC server started. Bound to: 127.28.113.193:39545
I20260812 06:20:25.988636 29733 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.113.193:39545 every 8 connection(s)
I20260812 06:20:25.998293 29734 heartbeater.cc:344] Connected to a master server at 127.28.113.254:43455
I20260812 06:20:25.998433 29734 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:25.998683 29734 heartbeater.cc:507] Master 127.28.113.254:43455 requested a full tablet report, sending...
I20260812 06:20:25.999362 29508 ts_manager.cc:194] Registered new tserver with Master: 857392f3a01c4a659799035404c5341a (127.28.113.193:39545)
I20260812 06:20:25.999626 29127 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012119459s
I20260812 06:20:26.000236 29508 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60536
I20260812 06:20:26.006654 29508 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60546:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:26.015606 29670 tablet_service.cc:1511] Processing CreateTablet for tablet 72fe02d7b5804e75950f985d839cd1b9 (DEFAULT_TABLE table=heavy-update-compaction-test [id=9fdf57ac71bb41f49f96208e7a80ee5a]), partition=
I20260812 06:20:26.015897 29670 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 72fe02d7b5804e75950f985d839cd1b9. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:26.017946 29753 tablet_bootstrap.cc:492] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Bootstrap starting.
I20260812 06:20:26.018795 29753 tablet_bootstrap.cc:654] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:26.019958 29753 tablet_bootstrap.cc:492] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: No bootstrap required, opened a new log
I20260812 06:20:26.020085 29753 ts_tablet_manager.cc:1403] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:26.020505 29753 raft_consensus.cc:359] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "857392f3a01c4a659799035404c5341a" member_type: VOTER last_known_addr { host: "127.28.113.193" port: 39545 } }
I20260812 06:20:26.020618 29753 raft_consensus.cc:385] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:26.020692 29753 raft_consensus.cc:740] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 857392f3a01c4a659799035404c5341a, State: Initialized, Role: FOLLOWER
I20260812 06:20:26.020823 29753 consensus_queue.cc:260] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a [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: "857392f3a01c4a659799035404c5341a" member_type: VOTER last_known_addr { host: "127.28.113.193" port: 39545 } }
I20260812 06:20:26.020922 29753 raft_consensus.cc:399] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:26.020975 29753 raft_consensus.cc:493] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:26.021051 29753 raft_consensus.cc:3060] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:26.021770 29753 raft_consensus.cc:515] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "857392f3a01c4a659799035404c5341a" member_type: VOTER last_known_addr { host: "127.28.113.193" port: 39545 } }
I20260812 06:20:26.021924 29753 leader_election.cc:304] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a [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: 857392f3a01c4a659799035404c5341a; no voters: 
I20260812 06:20:26.022140 29753 leader_election.cc:290] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:26.022349 29755 raft_consensus.cc:2804] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:26.022598 29755 raft_consensus.cc:697] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a [term 1 LEADER]: Becoming Leader. State: Replica: 857392f3a01c4a659799035404c5341a, State: Running, Role: LEADER
I20260812 06:20:26.022619 29753 ts_tablet_manager.cc:1434] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:26.022650 29734 heartbeater.cc:499] Master 127.28.113.254:43455 was elected leader, sending a full tablet report...
I20260812 06:20:26.022810 29755 consensus_queue.cc:237] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a [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: "857392f3a01c4a659799035404c5341a" member_type: VOTER last_known_addr { host: "127.28.113.193" port: 39545 } }
I20260812 06:20:26.024293 29508 catalog_manager.cc:5719] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a reported cstate change: term changed from 0 to 1, leader changed from <none> to 857392f3a01c4a659799035404c5341a (127.28.113.193). New cstate: current_term: 1 leader_uuid: "857392f3a01c4a659799035404c5341a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "857392f3a01c4a659799035404c5341a" member_type: VOTER last_known_addr { host: "127.28.113.193" port: 39545 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:26.083560 29127 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.018s	sys 0.004s
I20260812 06:20:26.239136 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushMRSOp(72fe02d7b5804e75950f985d839cd1b9): perf score=19.054940
I20260812 06:20:26.411571 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushMRSOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.172s	user 0.125s	sys 0.046s Metrics: {"bytes_written":12717736,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":107,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1057,"drs_written":1,"lbm_read_time_us":106,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43591,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1550}
I20260812 06:20:26.412494 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling LogGCOp(72fe02d7b5804e75950f985d839cd1b9): free 20743880 bytes of WAL
I20260812 06:20:26.412760 29633 log_reader.cc:385] T 72fe02d7b5804e75950f985d839cd1b9: removed 2 log segments from log reader
I20260812 06:20:26.412814 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000001 (ops 1-6)
I20260812 06:20:26.412858 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000002 (ops 7-11)
I20260812 06:20:26.418419 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: LogGCOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:26.418946 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:26.435680 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5618,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.436117 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:26.589754 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.153s	user 0.098s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":307,"lbm_read_time_us":9539,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25480,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":313,"threads_started":5,"update_count":2000}
I20260812 06:20:26.590261 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=14.095187
I20260812 06:20:26.654690 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.064s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":24280,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.655261 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:26.665338 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3943,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.665848 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling UndoDeltaBlockGCOp(72fe02d7b5804e75950f985d839cd1b9): 16411392 bytes on disk
I20260812 06:20:26.666296 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: UndoDeltaBlockGCOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.666715 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:26.830113 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.163s	user 0.116s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":208,"lbm_read_time_us":10742,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27841,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:26.830694 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=14.095187
I20260812 06:20:26.898856 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.068s	user 0.035s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22698,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.899534 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:26.910742 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.011s	user 0.003s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4490,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.911269 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:27.086727 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.175s	user 0.110s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":392,"lbm_read_time_us":12748,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27967,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:20:27.087666 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=10.126437
I20260812 06:20:27.129179 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.041s	user 0.018s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18212,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:27.129988 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:27.143433 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5280,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.143908 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:27.305114 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.161s	user 0.099s	sys 0.058s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":253,"lbm_read_time_us":11833,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23875,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:27.306910 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=10.126437
I20260812 06:20:27.348290 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.040s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16770,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:27.348905 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:27.377108 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.028s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6410,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.377619 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:27.387418 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3746,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.387936 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:27.537300 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.149s	user 0.129s	sys 0.020s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2040,"lbm_read_time_us":11474,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30398,"lbm_writes_lt_1ms":543,"mutex_wait_us":818,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18176,"update_count":2500}
I20260812 06:20:27.538064 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=11.118625
I20260812 06:20:27.576064 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.038s	user 0.030s	sys 0.007s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16740,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:27.576622 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:27.591427 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4855,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:27.591979 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushMRSOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:27.615811 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushMRSOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.024s	user 0.023s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":259,"dirs.run_wall_time_us":1151,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1327,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:27.616374 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling LogGCOp(72fe02d7b5804e75950f985d839cd1b9): free 112239310 bytes of WAL
I20260812 06:20:27.616603 29633 log_reader.cc:385] T 72fe02d7b5804e75950f985d839cd1b9: removed 11 log segments from log reader
I20260812 06:20:27.616648 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000003 (ops 12-16)
I20260812 06:20:27.616676 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000004 (ops 17-21)
I20260812 06:20:27.616739 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000005 (ops 22-26)
I20260812 06:20:27.616770 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000006 (ops 27-31)
I20260812 06:20:27.616806 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000007 (ops 32-36)
I20260812 06:20:27.616843 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000008 (ops 37-41)
I20260812 06:20:27.616883 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000009 (ops 42-46)
I20260812 06:20:27.616923 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000010 (ops 47-51)
I20260812 06:20:27.616961 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000011 (ops 52-56)
I20260812 06:20:27.616997 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000012 (ops 57-60)
I20260812 06:20:27.617044 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000013 (ops 61-65)
I20260812 06:20:27.641222 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: LogGCOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:27.641649 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling UndoDeltaBlockGCOp(72fe02d7b5804e75950f985d839cd1b9): 447 bytes on disk
I20260812 06:20:27.642153 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: UndoDeltaBlockGCOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:20:27.642686 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=5.165500
I20260812 06:20:27.662720 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.020s	user 0.014s	sys 0.003s Metrics: {"bytes_written":6482065,"delete_count":0,"lbm_write_time_us":8331,"lbm_writes_lt_1ms":161,"reinsert_count":0,"update_count":790}
I20260812 06:20:27.663282 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:27.672497 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":1723202,"delete_count":0,"lbm_write_time_us":2987,"lbm_writes_lt_1ms":45,"reinsert_count":0,"update_count":210}
I20260812 06:20:27.673058 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:27.861925 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.189s	user 0.139s	sys 0.041s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":475,"lbm_read_time_us":12896,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37463,"lbm_writes_lt_1ms":643,"mutex_wait_us":68,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7680,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:20:27.862658 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=14.095187
I20260812 06:20:27.919060 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.056s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21575,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:20:27.919612 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:27.936977 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6467,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.937768 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:28.087999 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.150s	user 0.132s	sys 0.015s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":11123,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28585,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:20:28.088693 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=10.126437
I20260812 06:20:28.122335 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.033s	user 0.014s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14529,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:28.122887 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:28.138067 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5520,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.138798 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:28.272972 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.134s	user 0.109s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1262,"lbm_read_time_us":7633,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29367,"lbm_writes_lt_1ms":443,"mutex_wait_us":195,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2000}
I20260812 06:20:28.273783 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=10.126437
I20260812 06:20:28.315073 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.041s	user 0.038s	sys 0.000s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17577,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:28.315685 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:28.333592 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.018s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6592,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.334050 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:28.464474 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.130s	user 0.094s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":168,"lbm_read_time_us":9850,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24038,"lbm_writes_lt_1ms":443,"mutex_wait_us":72,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:20:28.465059 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=10.126437
I20260812 06:20:28.517845 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.053s	user 0.021s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15542,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:28.518326 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:28.528808 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4178,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.529455 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:28.671454 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.142s	user 0.098s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3436,"lbm_read_time_us":10897,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22097,"lbm_writes_lt_1ms":443,"mutex_wait_us":2187,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.672194 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=10.126437
I20260812 06:20:28.711366 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.039s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14656,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:28.711863 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:28.722635 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4289,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.723318 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:28.852422 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.129s	user 0.088s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":789,"lbm_read_time_us":9031,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24074,"lbm_writes_lt_1ms":443,"mutex_wait_us":261,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2000}
I20260812 06:20:28.853195 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=10.126437
I20260812 06:20:28.891103 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.038s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15639,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:28.891705 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:28.903836 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.012s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4304,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.904273 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:29.022395 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.118s	user 0.088s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":383,"lbm_read_time_us":7579,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26342,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:20:29.023047 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=10.126437
I20260812 06:20:29.069621 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.046s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16247,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1500}
I20260812 06:20:29.070246 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:29.080611 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4022,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.081239 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushMRSOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:29.112246 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushMRSOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.031s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":1325,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1580,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:29.112917 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling LogGCOp(72fe02d7b5804e75950f985d839cd1b9): free 124710255 bytes of WAL
I20260812 06:20:29.113194 29633 log_reader.cc:385] T 72fe02d7b5804e75950f985d839cd1b9: removed 12 log segments from log reader
I20260812 06:20:29.113255 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000014 (ops 66-70)
I20260812 06:20:29.113297 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000015 (ops 71-75)
I20260812 06:20:29.113329 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000016 (ops 76-80)
I20260812 06:20:29.113353 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000017 (ops 81-85)
I20260812 06:20:29.113374 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000018 (ops 86-90)
I20260812 06:20:29.113404 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000019 (ops 91-95)
I20260812 06:20:29.113437 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000020 (ops 96-100)
I20260812 06:20:29.113463 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000021 (ops 101-105)
I20260812 06:20:29.113493 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000022 (ops 106-110)
I20260812 06:20:29.113519 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000023 (ops 111-115)
I20260812 06:20:29.113547 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000024 (ops 116-120)
I20260812 06:20:29.113577 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000025 (ops 121-125)
I20260812 06:20:29.141665 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: LogGCOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:29.142235 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling UndoDeltaBlockGCOp(72fe02d7b5804e75950f985d839cd1b9): 473 bytes on disk
I20260812 06:20:29.142773 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: UndoDeltaBlockGCOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:29.143436 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:29.164652 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.021s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4676,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.165076 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:29.175909 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4296,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.176376 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:29.347579 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.171s	user 0.122s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1120,"lbm_read_time_us":13728,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32029,"lbm_writes_lt_1ms":643,"mutex_wait_us":500,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9856,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:20:29.348162 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=14.095187
I20260812 06:20:29.406764 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.058s	user 0.034s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28933,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.407482 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:29.419981 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.420437 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:29.585891 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.165s	user 0.124s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":702,"lbm_read_time_us":11484,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29281,"lbm_writes_lt_1ms":543,"mutex_wait_us":302,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:20:29.586565 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=14.095187
I20260812 06:20:29.647835 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.061s	user 0.017s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24491,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.648346 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:29.659029 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4023,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.659703 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:29.839566 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.180s	user 0.109s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1421,"lbm_read_time_us":11393,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31919,"lbm_writes_lt_1ms":543,"mutex_wait_us":79,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:20:29.840406 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=14.095187
I20260812 06:20:29.907568 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.067s	user 0.026s	sys 0.039s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":25082,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.908293 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:29.925354 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.926045 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:30.115912 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.190s	user 0.139s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":394,"lbm_read_time_us":14495,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33112,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25472,"update_count":2500}
I20260812 06:20:30.116398 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=11.118625
I20260812 06:20:30.151733 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.035s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15553,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:30.152325 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:30.176323 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.024s	user 0.009s	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:20:30.177075 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:30.330899 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.154s	user 0.114s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":522,"lbm_read_time_us":9365,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25478,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:20:30.331643 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=14.095187
I20260812 06:20:30.381966 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.050s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20212,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.382484 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:30.392949 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3807,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.393767 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:30.542218 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.148s	user 0.097s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":233,"lbm_read_time_us":9313,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28367,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:30.542881 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=14.095187
I20260812 06:20:30.592701 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.050s	user 0.033s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18500,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.593220 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=2.188937
I20260812 06:20:30.604262 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3990,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.604756 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushMRSOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:30.636049 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushMRSOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.031s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":1145,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1434,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:30.636844 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling LogGCOp(72fe02d7b5804e75950f985d839cd1b9): free 124710549 bytes of WAL
I20260812 06:20:30.637109 29633 log_reader.cc:385] T 72fe02d7b5804e75950f985d839cd1b9: removed 12 log segments from log reader
I20260812 06:20:30.637176 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000026 (ops 126-130)
I20260812 06:20:30.637228 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000027 (ops 131-135)
I20260812 06:20:30.637285 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000028 (ops 136-140)
I20260812 06:20:30.637328 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000029 (ops 141-145)
I20260812 06:20:30.637367 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000030 (ops 146-150)
I20260812 06:20:30.637406 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000031 (ops 151-155)
I20260812 06:20:30.637446 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000032 (ops 156-160)
I20260812 06:20:30.637488 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000033 (ops 161-165)
I20260812 06:20:30.637527 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000034 (ops 166-170)
I20260812 06:20:30.637570 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000035 (ops 171-175)
I20260812 06:20:30.637609 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000036 (ops 176-180)
I20260812 06:20:30.637648 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000037 (ops 181-185)
I20260812 06:20:30.666769 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: LogGCOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:30.667172 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=3.181125
I20260812 06:20:30.685447 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":5251341,"delete_count":0,"lbm_write_time_us":7599,"lbm_writes_lt_1ms":131,"reinsert_count":0,"update_count":640}
I20260812 06:20:30.685966 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling LogGCOp(72fe02d7b5804e75950f985d839cd1b9): free 12018004 bytes of WAL
I20260812 06:20:30.686232 29633 log_reader.cc:385] T 72fe02d7b5804e75950f985d839cd1b9: removed 1 log segments from log reader
I20260812 06:20:30.686305 29633 log.cc:1079] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: Deleting log segment in path: /tmp/dist-test-taskY5hprL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620359630-29127-0/minicluster-data/ts-0-root/wals/72fe02d7b5804e75950f985d839cd1b9/wal-000000038 (ops 186-190)
I20260812 06:20:30.688555 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: LogGCOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:30.688884 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling UndoDeltaBlockGCOp(72fe02d7b5804e75950f985d839cd1b9): 482 bytes on disk
I20260812 06:20:30.689306 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: UndoDeltaBlockGCOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:20:30.690065 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.196750
I20260812 06:20:30.708810 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.019s	user 0.008s	sys 0.009s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":3685,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:20:30.709286 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9): perf score=1.000000
I20260812 06:20:30.937152 29127 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.853s	user 1.837s	sys 0.148s
I20260812 06:20:30.939327 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: MajorDeltaCompactionOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.230s	user 0.144s	sys 0.086s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979722,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":551,"lbm_read_time_us":14651,"lbm_reads_lt_1ms":766,"lbm_write_time_us":41559,"lbm_writes_lt_1ms":743,"mutex_wait_us":42,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":125,"threads_started":1,"update_count":3500}
I20260812 06:20:30.941376 29735 maintenance_manager.cc:419] P 857392f3a01c4a659799035404c5341a: Scheduling FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9): perf score=18.063937
I20260812 06:20:30.969861 29127 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.032s	user 0.002s	sys 0.000s
I20260812 06:20:30.970598 29127 tablet_server.cc:179] TabletServer@127.28.113.193:0 shutting down...
I20260812 06:20:31.002691 29633 maintenance_manager.cc:643] P 857392f3a01c4a659799035404c5341a: FlushDeltaMemStoresOp(72fe02d7b5804e75950f985d839cd1b9) complete. Timing: real 0.061s	user 0.031s	sys 0.026s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":23255,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:20:31.003530 29127 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:31.003790 29127 tablet_replica.cc:333] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a: stopping tablet replica
I20260812 06:20:31.003949 29127 raft_consensus.cc:2243] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.004137 29127 raft_consensus.cc:2272] T 72fe02d7b5804e75950f985d839cd1b9 P 857392f3a01c4a659799035404c5341a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.007848 29127 tablet_server.cc:196] TabletServer@127.28.113.193:0 shutdown complete.
I20260812 06:20:31.010582 29127 master.cc:562] Master@127.28.113.254:43455 shutting down...
I20260812 06:20:31.014901 29127 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.015093 29127 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.015168 29127 tablet_replica.cc:333] T 00000000000000000000000000000000 P 688162c877db4cef94cccbe324200ff0: stopping tablet replica
I20260812 06:20:31.027689 29127 master.cc:584] Master@127.28.113.254:43455 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5230 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10744 ms total)

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