[==========] 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:16:42.665678 31221 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.125.126:41915
I20260812 06:16:42.666816 31221 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:16:42.667514 31221 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:16:42.675449 31221 server_base.cc:1061] running on GCE node
W20260812 06:16:42.677314 31230 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:16:42.677350 31226 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:16:42.677558 31227 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:16:42.678110 31221 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:42.678206 31221 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:16:42.678234 31221 hybrid_clock.cc:648] HybridClock initialized: now 1786515402678233 us; error 0 us; skew 500 ppm
I20260812 06:16:42.680303 31221 webserver.cc:533] Webserver started at http://127.30.125.126:46511/ using document root <none> and password file <none>
I20260812 06:16:42.680853 31221 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:42.680915 31221 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:42.681118 31221 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:42.682858 31221 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/master-0-root/instance:
uuid: "6a03ffc5aa0942389e982423fab83037"
format_stamp: "Formatted at 2026-08-12 06:16:42 on dist-test-slave-wl2h"
I20260812 06:16:42.686870 31221 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:42.689472 31236 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:16:42.690804 31221 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:42.690994 31221 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/master-0-root
uuid: "6a03ffc5aa0942389e982423fab83037"
format_stamp: "Formatted at 2026-08-12 06:16:42 on dist-test-slave-wl2h"
I20260812 06:16:42.691246 31221 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-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:16:42.712724 31221 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:42.713549 31221 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:16:42.713768 31221 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:42.723096 31221 rpc_server.cc:307] RPC server started. Bound to: 127.30.125.126:41915
I20260812 06:16:42.723129 31294 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.125.126:41915 every 8 connection(s)
I20260812 06:16:42.725549 31295 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:16:42.731840 31295 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037: Bootstrap starting.
I20260812 06:16:42.734357 31295 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:42.735347 31295 log.cc:826] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:42.737267 31295 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037: No bootstrap required, opened a new log
I20260812 06:16:42.740366 31295 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a03ffc5aa0942389e982423fab83037" member_type: VOTER }
I20260812 06:16:42.740574 31295 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:42.740619 31295 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6a03ffc5aa0942389e982423fab83037, State: Initialized, Role: FOLLOWER
I20260812 06:16:42.741250 31295 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [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: "6a03ffc5aa0942389e982423fab83037" member_type: VOTER }
I20260812 06:16:42.741402 31295 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:42.741446 31295 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:42.741545 31295 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:42.742414 31295 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a03ffc5aa0942389e982423fab83037" member_type: VOTER }
I20260812 06:16:42.742846 31295 leader_election.cc:304] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [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: 6a03ffc5aa0942389e982423fab83037; no voters: 
I20260812 06:16:42.743244 31295 leader_election.cc:290] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:42.743606 31300 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:42.744031 31300 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [term 1 LEADER]: Becoming Leader. State: Replica: 6a03ffc5aa0942389e982423fab83037, State: Running, Role: LEADER
I20260812 06:16:42.744472 31295 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:42.744728 31300 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [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: "6a03ffc5aa0942389e982423fab83037" member_type: VOTER }
I20260812 06:16:42.746997 31221 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:42.747119 31302 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6a03ffc5aa0942389e982423fab83037" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a03ffc5aa0942389e982423fab83037" member_type: VOTER } }
I20260812 06:16:42.747246 31302 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:42.747260 31303 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6a03ffc5aa0942389e982423fab83037. Latest consensus state: current_term: 1 leader_uuid: "6a03ffc5aa0942389e982423fab83037" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a03ffc5aa0942389e982423fab83037" member_type: VOTER } }
I20260812 06:16:42.747351 31303 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [sys.catalog]: This master's current role is: LEADER
W20260812 06:16:42.749897 31316 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:16:42.749990 31316 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:16:42.750135 31319 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:42.751298 31319 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:42.758143 31319 catalog_manager.cc:1383] Generated new cluster ID: c136c413596c4d6cbe20325936372f78
I20260812 06:16:42.758256 31319 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:42.811353 31319 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:42.812893 31319 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:42.823513 31319 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037: Generated new TSK 0
I20260812 06:16:42.824297 31319 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:42.876695 31221 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:42.880932 31324 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:16:42.880970 31327 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:16:42.881349 31323 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:16:42.881386 31221 server_base.cc:1061] running on GCE node
I20260812 06:16:42.881691 31221 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:42.881807 31221 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:16:42.881846 31221 hybrid_clock.cc:648] HybridClock initialized: now 1786515402881846 us; error 0 us; skew 500 ppm
I20260812 06:16:42.882957 31221 webserver.cc:533] Webserver started at http://127.30.125.65:38063/ using document root <none> and password file <none>
I20260812 06:16:42.883181 31221 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:42.883270 31221 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:42.883359 31221 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:42.883812 31221 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/instance:
uuid: "8b6df2e746d642a19712b3b97d7d4f6c"
format_stamp: "Formatted at 2026-08-12 06:16:42 on dist-test-slave-wl2h"
I20260812 06:16:42.885483 31221 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:16:42.886680 31332 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:16:42.887120 31221 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:42.887215 31221 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root
uuid: "8b6df2e746d642a19712b3b97d7d4f6c"
format_stamp: "Formatted at 2026-08-12 06:16:42 on dist-test-slave-wl2h"
I20260812 06:16:42.887298 31221 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-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:16:42.903632 31221 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:42.904583 31221 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:42.905318 31221 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:42.906705 31221 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:42.906770 31221 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:42.906817 31221 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:42.906888 31221 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:42.932174 31221 rpc_server.cc:307] RPC server started. Bound to: 127.30.125.65:39625
I20260812 06:16:42.932626 31403 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.125.65:39625 every 8 connection(s)
I20260812 06:16:42.950814 31404 heartbeater.cc:344] Connected to a master server at 127.30.125.126:41915
I20260812 06:16:42.951177 31404 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:42.951715 31404 heartbeater.cc:507] Master 127.30.125.126:41915 requested a full tablet report, sending...
I20260812 06:16:42.953881 31253 ts_manager.cc:194] Registered new tserver with Master: 8b6df2e746d642a19712b3b97d7d4f6c (127.30.125.65:39625)
I20260812 06:16:42.954432 31221 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.021336221s
I20260812 06:16:42.956110 31253 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44432
I20260812 06:16:42.969892 31253 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44438:
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:16:42.990252 31361 tablet_service.cc:1511] Processing CreateTablet for tablet d335ac7660f147bb9d101fc29cdb82df (DEFAULT_TABLE table=heavy-update-compaction-test [id=aba0766eb5d84b5893641799cef40b99]), partition=
I20260812 06:16:42.990823 31361 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d335ac7660f147bb9d101fc29cdb82df. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:42.994112 31419 tablet_bootstrap.cc:492] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Bootstrap starting.
I20260812 06:16:42.995417 31419 tablet_bootstrap.cc:654] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:42.997978 31419 tablet_bootstrap.cc:492] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: No bootstrap required, opened a new log
I20260812 06:16:42.998157 31419 ts_tablet_manager.cc:1403] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Time spent bootstrapping tablet: real 0.004s	user 0.003s	sys 0.000s
I20260812 06:16:42.998988 31419 raft_consensus.cc:359] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8b6df2e746d642a19712b3b97d7d4f6c" member_type: VOTER last_known_addr { host: "127.30.125.65" port: 39625 } }
I20260812 06:16:42.999189 31419 raft_consensus.cc:385] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:42.999267 31419 raft_consensus.cc:740] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8b6df2e746d642a19712b3b97d7d4f6c, State: Initialized, Role: FOLLOWER
I20260812 06:16:42.999420 31419 consensus_queue.cc:260] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c [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: "8b6df2e746d642a19712b3b97d7d4f6c" member_type: VOTER last_known_addr { host: "127.30.125.65" port: 39625 } }
I20260812 06:16:42.999536 31419 raft_consensus.cc:399] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:42.999586 31419 raft_consensus.cc:493] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:42.999639 31419 raft_consensus.cc:3060] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:43.000890 31419 raft_consensus.cc:515] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8b6df2e746d642a19712b3b97d7d4f6c" member_type: VOTER last_known_addr { host: "127.30.125.65" port: 39625 } }
I20260812 06:16:43.001168 31419 leader_election.cc:304] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c [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: 8b6df2e746d642a19712b3b97d7d4f6c; no voters: 
I20260812 06:16:43.001571 31419 leader_election.cc:290] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:43.001853 31421 raft_consensus.cc:2804] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:43.002059 31419 ts_tablet_manager.cc:1434] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Time spent starting tablet: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:16:43.002172 31421 raft_consensus.cc:697] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c [term 1 LEADER]: Becoming Leader. State: Replica: 8b6df2e746d642a19712b3b97d7d4f6c, State: Running, Role: LEADER
I20260812 06:16:43.002342 31404 heartbeater.cc:499] Master 127.30.125.126:41915 was elected leader, sending a full tablet report...
I20260812 06:16:43.002347 31421 consensus_queue.cc:237] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c [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: "8b6df2e746d642a19712b3b97d7d4f6c" member_type: VOTER last_known_addr { host: "127.30.125.65" port: 39625 } }
I20260812 06:16:43.007288 31253 catalog_manager.cc:5719] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c reported cstate change: term changed from 0 to 1, leader changed from <none> to 8b6df2e746d642a19712b3b97d7d4f6c (127.30.125.65). New cstate: current_term: 1 leader_uuid: "8b6df2e746d642a19712b3b97d7d4f6c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8b6df2e746d642a19712b3b97d7d4f6c" member_type: VOTER last_known_addr { host: "127.30.125.65" port: 39625 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:43.166074 31221 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.143s	user 0.019s	sys 0.030s
I20260812 06:16:43.184425 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushMRSOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.187753
I20260812 06:16:43.286094 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushMRSOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.101s	user 0.087s	sys 0.008s Metrics: {"bytes_written":4512903,"cfile_init":1,"compiler_manager_pool.queue_time_us":1285,"delete_count":0,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":905,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":13667,"lbm_writes_lt_1ms":167,"peak_mem_usage":0,"reinsert_count":0,"rows_written":100,"thread_start_us":227,"threads_started":1,"update_count":550}
I20260812 06:16:43.287740 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:43.302670 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5596,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:43.303808 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling UndoDeltaBlockGCOp(d335ac7660f147bb9d101fc29cdb82df): 766 bytes on disk
I20260812 06:16:43.304536 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: UndoDeltaBlockGCOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4}
I20260812 06:16:43.305105 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:43.417276 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.112s	user 0.074s	sys 0.036s Metrics: {"cfile_cache_miss":232,"cfile_cache_miss_bytes":12303557,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":483,"lbm_read_time_us":6236,"lbm_reads_lt_1ms":264,"lbm_write_time_us":18112,"lbm_writes_lt_1ms":243,"peak_mem_usage":25836184,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":294,"threads_started":5,"update_count":1000}
I20260812 06:16:43.417845 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=6.157687
I20260812 06:16:43.451047 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.033s	user 0.012s	sys 0.013s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":12169,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:43.451642 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:43.544622 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.093s	user 0.067s	sys 0.023s Metrics: {"cfile_cache_miss":231,"cfile_cache_miss_bytes":12303448,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":345,"lbm_read_time_us":4944,"lbm_reads_lt_1ms":263,"lbm_write_time_us":16652,"lbm_writes_lt_1ms":243,"mutex_wait_us":40,"peak_mem_usage":25836184,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":1000}
I20260812 06:16:43.546985 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=8.142062
I20260812 06:16:43.577613 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.030s	user 0.018s	sys 0.009s Metrics: {"bytes_written":9435802,"delete_count":0,"lbm_write_time_us":14007,"lbm_writes_lt_1ms":233,"reinsert_count":0,"update_count":1150}
I20260812 06:16:43.578346 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.196750
I20260812 06:16:43.593780 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.015s	user 0.011s	sys 0.000s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":4913,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:16:43.594267 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:43.722802 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.128s	user 0.071s	sys 0.057s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16405950,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":585,"lbm_read_time_us":9061,"lbm_reads_lt_1ms":368,"lbm_write_time_us":24636,"lbm_writes_lt_1ms":343,"mutex_wait_us":25,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":18304,"update_count":1500}
I20260812 06:16:43.723433 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=10.126437
I20260812 06:16:43.776696 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.053s	user 0.032s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":25461,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:43.777582 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:43.790369 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4865,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.790951 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:43.932054 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.141s	user 0.104s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20508391,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":366,"lbm_read_time_us":9859,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27984,"lbm_writes_lt_1ms":443,"mutex_wait_us":68,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2000}
I20260812 06:16:43.932773 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=10.126437
I20260812 06:16:43.979954 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.047s	user 0.018s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23890,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:43.980496 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:43.998337 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.018s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7015,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.998917 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:44.138989 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.140s	user 0.098s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20508392,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1185,"lbm_read_time_us":9804,"lbm_reads_lt_1ms":464,"lbm_write_time_us":30576,"lbm_writes_lt_1ms":443,"mutex_wait_us":273,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":148352,"update_count":2000}
I20260812 06:16:44.139570 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=11.118625
I20260812 06:16:44.193218 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.053s	user 0.021s	sys 0.030s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":21021,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:44.194046 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:44.211292 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6673,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:44.211771 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:44.369155 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.157s	user 0.102s	sys 0.053s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20508384,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":331,"lbm_read_time_us":9053,"lbm_reads_lt_1ms":468,"lbm_write_time_us":30978,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:44.369860 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=10.126437
I20260812 06:16:44.416720 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.047s	user 0.021s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21114,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:44.417672 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:44.435784 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.018s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7662,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.436254 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:44.586149 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.150s	user 0.120s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20508393,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1003,"lbm_read_time_us":10000,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32531,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":2000}
I20260812 06:16:44.586921 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=11.118625
I20260812 06:16:44.637876 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.051s	user 0.038s	sys 0.009s Metrics: {"bytes_written":12963877,"delete_count":0,"lbm_write_time_us":24546,"lbm_writes_lt_1ms":319,"reinsert_count":0,"update_count":1580}
I20260812 06:16:44.638415 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:44.650311 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":3859,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:16:44.650784 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:44.661752 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.011s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4413,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:44.662309 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushMRSOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:44.696931 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushMRSOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1152505,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":453,"dirs.run_wall_time_us":1507,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2239,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:44.697778 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling LogGCOp(d335ac7660f147bb9d101fc29cdb82df): free 112651221 bytes of WAL
I20260812 06:16:44.698068 31337 log_reader.cc:385] T d335ac7660f147bb9d101fc29cdb82df: removed 11 log segments from log reader
I20260812 06:16:44.698124 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000001 (ops 1-6)
I20260812 06:16:44.698190 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000002 (ops 7-11)
I20260812 06:16:44.698237 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000003 (ops 12-16)
I20260812 06:16:44.698263 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000004 (ops 17-21)
I20260812 06:16:44.698305 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000005 (ops 22-26)
I20260812 06:16:44.698347 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000006 (ops 27-31)
I20260812 06:16:44.698386 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000007 (ops 32-36)
I20260812 06:16:44.698427 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000008 (ops 37-41)
I20260812 06:16:44.698467 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000009 (ops 42-46)
I20260812 06:16:44.698503 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000010 (ops 47-51)
I20260812 06:16:44.698544 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000011 (ops 52-56)
I20260812 06:16:44.722347 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: LogGCOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:16:44.723171 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling UndoDeltaBlockGCOp(d335ac7660f147bb9d101fc29cdb82df): 448 bytes on disk
I20260812 06:16:44.723821 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: UndoDeltaBlockGCOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:16:44.724466 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:44.740361 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.016s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4312,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.740892 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:44.751768 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4075,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.752486 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:44.958482 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.206s	user 0.170s	sys 0.035s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32815968,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":709,"lbm_read_time_us":12213,"lbm_reads_lt_1ms":775,"lbm_write_time_us":43451,"lbm_writes_lt_1ms":743,"mutex_wait_us":25,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14208,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:16:44.959197 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=14.095187
I20260812 06:16:45.028601 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.069s	user 0.036s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25551,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:45.029241 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:45.058166 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.029s	user 0.007s	sys 0.019s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6419,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.058780 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:45.236402 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.177s	user 0.146s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24610804,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":987,"lbm_read_time_us":12044,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30054,"lbm_writes_lt_1ms":543,"mutex_wait_us":316,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19456,"update_count":2500}
I20260812 06:16:45.237138 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=10.126437
I20260812 06:16:45.282450 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.045s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21406,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:45.283277 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:45.305183 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.022s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7678,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.306229 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:45.468189 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.162s	user 0.118s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20508392,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":596,"lbm_read_time_us":9224,"lbm_reads_lt_1ms":464,"lbm_write_time_us":40070,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":102,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:45.469152 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=14.095187
I20260812 06:16:45.541958 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.072s	user 0.040s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":37779,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:45.542553 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:45.557682 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5163,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.558212 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:45.765534 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.207s	user 0.126s	sys 0.079s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24610804,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":163,"lbm_read_time_us":11589,"lbm_reads_lt_1ms":572,"lbm_write_time_us":64225,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":539,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2500}
I20260812 06:16:45.766444 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=14.095187
I20260812 06:16:45.837817 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.071s	user 0.036s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":38333,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:16:45.838536 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:45.854512 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6315,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.855257 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:46.065594 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.210s	user 0.136s	sys 0.074s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24610803,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1148,"lbm_read_time_us":12192,"lbm_reads_lt_1ms":572,"lbm_write_time_us":59721,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21632,"update_count":2500}
I20260812 06:16:46.066385 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=14.095187
I20260812 06:16:46.124977 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.058s	user 0.040s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":26436,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:46.125563 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:46.308073 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.182s	user 0.099s	sys 0.076s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20508271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":294,"lbm_read_time_us":10707,"lbm_reads_lt_1ms":463,"lbm_write_time_us":40151,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":401,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:46.308665 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=14.095187
I20260812 06:16:46.369079 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.060s	user 0.042s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":32310,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:46.369645 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:46.400027 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.030s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5946,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":500}
I20260812 06:16:46.400733 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushMRSOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:46.446548 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushMRSOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.046s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":38,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1496,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2165,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:46.447502 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=3.181125
I20260812 06:16:46.470045 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.022s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":8003,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:46.470593 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling LogGCOp(d335ac7660f147bb9d101fc29cdb82df): free 132571264 bytes of WAL
I20260812 06:16:46.470870 31337 log_reader.cc:385] T d335ac7660f147bb9d101fc29cdb82df: removed 13 log segments from log reader
I20260812 06:16:46.470942 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000012 (ops 57-61)
I20260812 06:16:46.470990 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000013 (ops 62-66)
I20260812 06:16:46.471081 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000014 (ops 67-71)
I20260812 06:16:46.471122 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000015 (ops 72-76)
I20260812 06:16:46.471164 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000016 (ops 77-81)
I20260812 06:16:46.471208 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000017 (ops 82-86)
I20260812 06:16:46.471251 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000018 (ops 87-90)
I20260812 06:16:46.471290 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000019 (ops 91-95)
I20260812 06:16:46.471329 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000020 (ops 96-100)
I20260812 06:16:46.471369 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000021 (ops 101-105)
I20260812 06:16:46.471408 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000022 (ops 106-110)
I20260812 06:16:46.471448 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000023 (ops 111-114)
I20260812 06:16:46.471487 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000024 (ops 115-119)
I20260812 06:16:46.500304 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: LogGCOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:16:46.501034 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling UndoDeltaBlockGCOp(d335ac7660f147bb9d101fc29cdb82df): 482 bytes on disk
I20260812 06:16:46.501574 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: UndoDeltaBlockGCOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":93,"lbm_reads_lt_1ms":4}
I20260812 06:16:46.502255 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:46.522758 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.020s	user 0.009s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6043,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:46.523299 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:46.534658 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4380,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:46.535275 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:46.795207 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.260s	user 0.208s	sys 0.044s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":36918388,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1342,"lbm_read_time_us":16236,"lbm_reads_lt_1ms":875,"lbm_write_time_us":49379,"lbm_writes_lt_1ms":843,"mutex_wait_us":314,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":83,"threads_started":1,"update_count":4000}
I20260812 06:16:46.795831 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=18.063937
I20260812 06:16:46.868551 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.073s	user 0.050s	sys 0.020s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":32409,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:16:46.869356 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:46.885859 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.016s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6434,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:46.886384 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:47.114982 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.228s	user 0.159s	sys 0.059s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28713215,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1983,"lbm_read_time_us":11346,"lbm_reads_lt_1ms":664,"lbm_write_time_us":59388,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":412,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:16:47.115913 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=18.063937
I20260812 06:16:47.180305 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.064s	user 0.044s	sys 0.019s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":29904,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:16:47.181005 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:47.200134 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.019s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6402,"lbm_writes_lt_1ms":103,"mutex_wait_us":106,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.200692 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:47.417207 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.216s	user 0.162s	sys 0.039s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28713217,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":465,"lbm_read_time_us":13151,"lbm_reads_lt_1ms":664,"lbm_write_time_us":62911,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":3000}
I20260812 06:16:47.417845 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=18.063937
I20260812 06:16:47.497053 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.079s	user 0.058s	sys 0.020s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":41524,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:47.497670 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:47.520394 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.023s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5787,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.520907 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:47.534858 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5166,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.535543 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:47.777202 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.241s	user 0.133s	sys 0.107s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32815751,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":326,"lbm_read_time_us":12801,"lbm_reads_lt_1ms":773,"lbm_write_time_us":84207,"lbm_writes_lt_1ms":743,"mutex_wait_us":43,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":3500}
I20260812 06:16:47.777920 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=15.087375
I20260812 06:16:47.846800 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.069s	user 0.048s	sys 0.017s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":40213,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":410,"reinsert_count":0,"update_count":2050}
I20260812 06:16:47.847321 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=6.157687
I20260812 06:16:47.880656 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.033s	user 0.010s	sys 0.009s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8716,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:16:47.881356 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:47.893630 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4405,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.894156 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushMRSOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:47.921336 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushMRSOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.027s	user 0.022s	sys 0.003s Metrics: {"bytes_written":1152511,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1547,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2194,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:47.922154 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling LogGCOp(d335ac7660f147bb9d101fc29cdb82df): free 112239563 bytes of WAL
I20260812 06:16:47.922430 31337 log_reader.cc:385] T d335ac7660f147bb9d101fc29cdb82df: removed 11 log segments from log reader
I20260812 06:16:47.922492 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000025 (ops 120-124)
I20260812 06:16:47.922531 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000026 (ops 125-129)
I20260812 06:16:47.922554 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000027 (ops 130-134)
I20260812 06:16:47.922585 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000028 (ops 135-139)
I20260812 06:16:47.922609 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000029 (ops 140-144)
I20260812 06:16:47.922644 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000030 (ops 145-149)
I20260812 06:16:47.922672 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000031 (ops 150-154)
I20260812 06:16:47.922695 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000032 (ops 155-159)
I20260812 06:16:47.922726 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000033 (ops 160-164)
I20260812 06:16:47.922756 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000034 (ops 165-168)
I20260812 06:16:47.922781 31337 log.cc:1079] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/d335ac7660f147bb9d101fc29cdb82df/wal-000000035 (ops 169-173)
I20260812 06:16:47.951787 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: LogGCOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.029s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:16:47.952622 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:47.978113 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.025s	user 0.008s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6240,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.978806 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling UndoDeltaBlockGCOp(d335ac7660f147bb9d101fc29cdb82df): 448 bytes on disk
I20260812 06:16:47.979346 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: UndoDeltaBlockGCOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:16:47.979871 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:47.993645 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4716,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.994138 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:48.230216 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.236s	user 0.178s	sys 0.058s Metrics: {"cfile_cache_miss":935,"cfile_cache_miss_bytes":41020807,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":802,"lbm_read_time_us":20096,"lbm_reads_lt_1ms":975,"lbm_write_time_us":46186,"lbm_writes_lt_1ms":943,"mutex_wait_us":98,"peak_mem_usage":112822188,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":93,"threads_started":1,"update_count":4500}
I20260812 06:16:48.230985 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=18.063937
I20260812 06:16:48.309757 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.079s	user 0.042s	sys 0.031s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":32960,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:48.310546 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:48.332120 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.021s	user 0.016s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7357,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.333073 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:48.560487 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.227s	user 0.147s	sys 0.080s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28713219,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":407,"lbm_read_time_us":14617,"lbm_reads_lt_1ms":664,"lbm_write_time_us":44625,"lbm_writes_lt_1ms":643,"mutex_wait_us":37,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":62080,"update_count":3000}
I20260812 06:16:48.561213 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=14.095187
I20260812 06:16:48.618037 31221 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.452s	user 1.952s	sys 0.121s
I20260812 06:16:48.622732 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.061s	user 0.032s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":32072,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:48.623292 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df): perf score=2.188937
I20260812 06:16:48.634063 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: FlushDeltaMemStoresOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4282,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.634552 31406 maintenance_manager.cc:419] P 8b6df2e746d642a19712b3b97d7d4f6c: Scheduling MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df): perf score=1.000000
I20260812 06:16:48.663213 31221 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.045s	user 0.004s	sys 0.000s
I20260812 06:16:48.663890 31221 tablet_server.cc:179] TabletServer@127.30.125.65:0 shutting down...
I20260812 06:16:48.784334 31337 maintenance_manager.cc:643] P 8b6df2e746d642a19712b3b97d7d4f6c: MajorDeltaCompactionOp(d335ac7660f147bb9d101fc29cdb82df) complete. Timing: real 0.150s	user 0.106s	sys 0.044s Metrics: {"cfile_cache_hit":28,"cfile_cache_hit_bytes":3803450,"cfile_cache_miss":504,"cfile_cache_miss_bytes":20807354,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":488,"lbm_read_time_us":8659,"lbm_reads_lt_1ms":520,"lbm_write_time_us":27735,"lbm_writes_lt_1ms":543,"mutex_wait_us":94,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:16:48.785408 31221 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:48.785873 31221 tablet_replica.cc:333] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c: stopping tablet replica
I20260812 06:16:48.786123 31221 raft_consensus.cc:2243] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:48.786405 31221 raft_consensus.cc:2272] T d335ac7660f147bb9d101fc29cdb82df P 8b6df2e746d642a19712b3b97d7d4f6c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:48.804689 31221 tablet_server.cc:196] TabletServer@127.30.125.65:0 shutdown complete.
I20260812 06:16:48.835233 31221 master.cc:562] Master@127.30.125.126:41915 shutting down...
I20260812 06:16:48.841226 31221 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:48.841564 31221 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:48.841637 31221 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6a03ffc5aa0942389e982423fab83037: stopping tablet replica
I20260812 06:16:48.855090 31221 master.cc:584] Master@127.30.125.126:41915 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6290 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:48.954909 31221 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.125.126:38993
I20260812 06:16:48.955381 31221 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:48.957669 31439 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:16:48.957715 31442 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:16:48.957940 31440 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:16:48.958104 31221 server_base.cc:1061] running on GCE node
I20260812 06:16:48.958302 31221 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:48.958340 31221 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:16:48.958355 31221 hybrid_clock.cc:648] HybridClock initialized: now 1786515408958356 us; error 0 us; skew 500 ppm
I20260812 06:16:48.959441 31221 webserver.cc:533] Webserver started at http://127.30.125.126:40361/ using document root <none> and password file <none>
I20260812 06:16:48.959702 31221 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:48.959789 31221 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:48.959884 31221 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:48.960368 31221 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/master-0-root/instance:
uuid: "a8ec07c871344c3b8a0228f6b975ab57"
format_stamp: "Formatted at 2026-08-12 06:16:48 on dist-test-slave-wl2h"
I20260812 06:16:48.962155 31221 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:48.963404 31448 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:16:48.963773 31221 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:48.963883 31221 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/master-0-root
uuid: "a8ec07c871344c3b8a0228f6b975ab57"
format_stamp: "Formatted at 2026-08-12 06:16:48 on dist-test-slave-wl2h"
I20260812 06:16:48.963989 31221 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-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:16:48.983393 31221 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:48.983858 31221 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:48.989388 31221 rpc_server.cc:307] RPC server started. Bound to: 127.30.125.126:38993
I20260812 06:16:48.990777 31517 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.125.126:38993 every 8 connection(s)
I20260812 06:16:48.992753 31518 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:16:49.006443 31518 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57: Bootstrap starting.
I20260812 06:16:49.008220 31518 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:49.009780 31518 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57: No bootstrap required, opened a new log
I20260812 06:16:49.010653 31518 raft_consensus.cc:359] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a8ec07c871344c3b8a0228f6b975ab57" member_type: VOTER }
I20260812 06:16:49.010766 31518 raft_consensus.cc:385] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:49.010789 31518 raft_consensus.cc:740] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a8ec07c871344c3b8a0228f6b975ab57, State: Initialized, Role: FOLLOWER
I20260812 06:16:49.010967 31518 consensus_queue.cc:260] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [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: "a8ec07c871344c3b8a0228f6b975ab57" member_type: VOTER }
I20260812 06:16:49.011138 31518 raft_consensus.cc:399] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:49.011168 31518 raft_consensus.cc:493] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:49.011199 31518 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:49.012127 31518 raft_consensus.cc:515] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a8ec07c871344c3b8a0228f6b975ab57" member_type: VOTER }
I20260812 06:16:49.012259 31518 leader_election.cc:304] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [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: a8ec07c871344c3b8a0228f6b975ab57; no voters: 
I20260812 06:16:49.012498 31518 leader_election.cc:290] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:49.012701 31521 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:49.013082 31518 sys_catalog.cc:565] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:49.013350 31521 raft_consensus.cc:697] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [term 1 LEADER]: Becoming Leader. State: Replica: a8ec07c871344c3b8a0228f6b975ab57, State: Running, Role: LEADER
I20260812 06:16:49.013550 31521 consensus_queue.cc:237] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [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: "a8ec07c871344c3b8a0228f6b975ab57" member_type: VOTER }
I20260812 06:16:49.014107 31524 sys_catalog.cc:455] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [sys.catalog]: SysCatalogTable state changed. Reason: New leader a8ec07c871344c3b8a0228f6b975ab57. Latest consensus state: current_term: 1 leader_uuid: "a8ec07c871344c3b8a0228f6b975ab57" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a8ec07c871344c3b8a0228f6b975ab57" member_type: VOTER } }
I20260812 06:16:49.014367 31523 sys_catalog.cc:455] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a8ec07c871344c3b8a0228f6b975ab57" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a8ec07c871344c3b8a0228f6b975ab57" member_type: VOTER } }
I20260812 06:16:49.014631 31523 sys_catalog.cc:458] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:49.014978 31524 sys_catalog.cc:458] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:49.015214 31528 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:49.016079 31528 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:49.016602 31221 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:49.018723 31528 catalog_manager.cc:1383] Generated new cluster ID: 274926a427ea408f818f21e2c1f3666e
I20260812 06:16:49.018833 31528 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:49.034222 31528 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:49.034920 31528 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:49.040608 31528 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57: Generated new TSK 0
I20260812 06:16:49.040802 31528 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:49.050060 31221 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:49.052645 31545 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:16:49.052668 31547 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:16:49.052786 31221 server_base.cc:1061] running on GCE node
W20260812 06:16:49.052693 31544 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:16:49.053257 31221 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:49.053339 31221 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:16:49.053375 31221 hybrid_clock.cc:648] HybridClock initialized: now 1786515409053374 us; error 0 us; skew 500 ppm
I20260812 06:16:49.054375 31221 webserver.cc:533] Webserver started at http://127.30.125.65:41803/ using document root <none> and password file <none>
I20260812 06:16:49.054570 31221 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:49.054648 31221 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:49.054730 31221 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:49.055240 31221 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/instance:
uuid: "b0b4fbf5e84149b99ef0a787c7539227"
format_stamp: "Formatted at 2026-08-12 06:16:49 on dist-test-slave-wl2h"
I20260812 06:16:49.056907 31221 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:49.058266 31553 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:16:49.058782 31221 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:49.058903 31221 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root
uuid: "b0b4fbf5e84149b99ef0a787c7539227"
format_stamp: "Formatted at 2026-08-12 06:16:49 on dist-test-slave-wl2h"
I20260812 06:16:49.059005 31221 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-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:16:49.069255 31221 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:49.069720 31221 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:49.070075 31221 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:49.070627 31221 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:49.070693 31221 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:49.070756 31221 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:49.070791 31221 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:49.075948 31221 rpc_server.cc:307] RPC server started. Bound to: 127.30.125.65:38289
I20260812 06:16:49.075968 31631 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.125.65:38289 every 8 connection(s)
I20260812 06:16:49.085829 31632 heartbeater.cc:344] Connected to a master server at 127.30.125.126:38993
I20260812 06:16:49.085980 31632 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:49.086229 31632 heartbeater.cc:507] Master 127.30.125.126:38993 requested a full tablet report, sending...
I20260812 06:16:49.087352 31475 ts_manager.cc:194] Registered new tserver with Master: b0b4fbf5e84149b99ef0a787c7539227 (127.30.125.65:38289)
I20260812 06:16:49.088140 31221 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011674389s
I20260812 06:16:49.088567 31475 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50078
I20260812 06:16:49.097200 31475 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50080:
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:16:49.109124 31587 tablet_service.cc:1511] Processing CreateTablet for tablet 826067df6bc040a0ad85fe9fc0cba0ba (DEFAULT_TABLE table=heavy-update-compaction-test [id=1832425ee1374a68bdf3c4b971961629]), partition=
I20260812 06:16:49.109579 31587 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 826067df6bc040a0ad85fe9fc0cba0ba. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:49.112785 31645 tablet_bootstrap.cc:492] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Bootstrap starting.
I20260812 06:16:49.114056 31645 tablet_bootstrap.cc:654] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:49.115661 31645 tablet_bootstrap.cc:492] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: No bootstrap required, opened a new log
I20260812 06:16:49.115837 31645 ts_tablet_manager.cc:1403] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:49.116318 31645 raft_consensus.cc:359] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b0b4fbf5e84149b99ef0a787c7539227" member_type: VOTER last_known_addr { host: "127.30.125.65" port: 38289 } }
I20260812 06:16:49.116448 31645 raft_consensus.cc:385] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:49.116495 31645 raft_consensus.cc:740] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b0b4fbf5e84149b99ef0a787c7539227, State: Initialized, Role: FOLLOWER
I20260812 06:16:49.116706 31645 consensus_queue.cc:260] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227 [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: "b0b4fbf5e84149b99ef0a787c7539227" member_type: VOTER last_known_addr { host: "127.30.125.65" port: 38289 } }
I20260812 06:16:49.116820 31645 raft_consensus.cc:399] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:49.116870 31645 raft_consensus.cc:493] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:49.116925 31645 raft_consensus.cc:3060] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:49.117805 31645 raft_consensus.cc:515] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b0b4fbf5e84149b99ef0a787c7539227" member_type: VOTER last_known_addr { host: "127.30.125.65" port: 38289 } }
I20260812 06:16:49.117991 31645 leader_election.cc:304] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227 [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: b0b4fbf5e84149b99ef0a787c7539227; no voters: 
I20260812 06:16:49.118295 31645 leader_election.cc:290] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:49.118395 31648 raft_consensus.cc:2804] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:49.118573 31648 raft_consensus.cc:697] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227 [term 1 LEADER]: Becoming Leader. State: Replica: b0b4fbf5e84149b99ef0a787c7539227, State: Running, Role: LEADER
I20260812 06:16:49.118672 31645 ts_tablet_manager.cc:1434] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:49.118744 31648 consensus_queue.cc:237] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227 [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: "b0b4fbf5e84149b99ef0a787c7539227" member_type: VOTER last_known_addr { host: "127.30.125.65" port: 38289 } }
I20260812 06:16:49.118870 31632 heartbeater.cc:499] Master 127.30.125.126:38993 was elected leader, sending a full tablet report...
I20260812 06:16:49.120327 31475 catalog_manager.cc:5719] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227 reported cstate change: term changed from 0 to 1, leader changed from <none> to b0b4fbf5e84149b99ef0a787c7539227 (127.30.125.65). New cstate: current_term: 1 leader_uuid: "b0b4fbf5e84149b99ef0a787c7539227" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b0b4fbf5e84149b99ef0a787c7539227" member_type: VOTER last_known_addr { host: "127.30.125.65" port: 38289 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:49.184581 31221 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.013s	sys 0.012s
I20260812 06:16:49.327045 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushMRSOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=15.086190
I20260812 06:16:49.491246 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushMRSOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.164s	user 0.114s	sys 0.049s Metrics: {"bytes_written":11897249,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":997,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41674,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1450}
I20260812 06:16:49.492246 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling LogGCOp(826067df6bc040a0ad85fe9fc0cba0ba): free 20743880 bytes of WAL
I20260812 06:16:49.492563 31558 log_reader.cc:385] T 826067df6bc040a0ad85fe9fc0cba0ba: removed 2 log segments from log reader
I20260812 06:16:49.492614 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000001 (ops 1-6)
I20260812 06:16:49.492651 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000002 (ops 7-11)
I20260812 06:16:49.497821 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: LogGCOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:16:49.498364 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling UndoDeltaBlockGCOp(826067df6bc040a0ad85fe9fc0cba0ba): 12719217 bytes on disk
I20260812 06:16:49.499109 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: UndoDeltaBlockGCOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.001s	user 0.001s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":134,"lbm_reads_lt_1ms":4}
I20260812 06:16:49.499949 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:49.521452 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.021s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6615,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.522307 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:49.671870 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.149s	user 0.110s	sys 0.039s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":716,"lbm_read_time_us":10166,"lbm_reads_lt_1ms":450,"lbm_write_time_us":27204,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"thread_start_us":434,"threads_started":5,"update_count":1950}
I20260812 06:16:49.672648 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=11.118625
I20260812 06:16:49.705565 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.033s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":14370,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:49.706254 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:49.720239 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5062,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:49.721206 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:49.851630 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.130s	user 0.083s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":281,"lbm_read_time_us":9257,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24346,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18816,"update_count":2000}
I20260812 06:16:49.852336 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=10.126437
I20260812 06:16:49.915637 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.063s	user 0.037s	sys 0.022s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19897,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:49.916375 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:49.928913 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4864,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.929441 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:50.118098 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.188s	user 0.127s	sys 0.059s 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":1236,"lbm_read_time_us":12358,"lbm_reads_lt_1ms":472,"lbm_write_time_us":33299,"lbm_writes_lt_1ms":443,"mutex_wait_us":298,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2000}
I20260812 06:16:50.118804 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=10.126437
I20260812 06:16:50.168022 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.049s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16963,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.168531 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:50.180740 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4913,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.181602 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:50.317044 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.135s	user 0.095s	sys 0.040s 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":595,"lbm_read_time_us":9108,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27597,"lbm_writes_lt_1ms":443,"mutex_wait_us":110,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2000}
I20260812 06:16:50.317754 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=10.126437
I20260812 06:16:50.369648 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.052s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18708,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.370466 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:50.382673 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.012s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4860,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.383584 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:50.520064 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.136s	user 0.113s	sys 0.022s 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":243,"lbm_read_time_us":10193,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25858,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:16:50.520780 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=10.126437
I20260812 06:16:50.589476 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.068s	user 0.029s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20193,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.590197 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:50.602135 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4582,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.602641 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:50.774073 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.171s	user 0.125s	sys 0.043s 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":1914,"lbm_read_time_us":12011,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26421,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:16:50.774983 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=11.118625
I20260812 06:16:50.812041 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.037s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15710,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:50.812943 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:50.831651 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.018s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6468,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:50.832540 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushMRSOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:50.873198 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushMRSOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.040s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":40,"dirs.run_cpu_time_us":324,"dirs.run_wall_time_us":1860,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2086,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:50.874051 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling UndoDeltaBlockGCOp(826067df6bc040a0ad85fe9fc0cba0ba): 448 bytes on disk
I20260812 06:16:50.874447 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: UndoDeltaBlockGCOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:16:50.874882 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=3.181125
I20260812 06:16:50.896925 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.022s	user 0.012s	sys 0.006s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4267,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:50.897554 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling LogGCOp(826067df6bc040a0ad85fe9fc0cba0ba): free 112239263 bytes of WAL
I20260812 06:16:50.897802 31558 log_reader.cc:385] T 826067df6bc040a0ad85fe9fc0cba0ba: removed 11 log segments from log reader
I20260812 06:16:50.897850 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000003 (ops 12-16)
I20260812 06:16:50.897882 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000004 (ops 17-20)
I20260812 06:16:50.897899 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000005 (ops 21-25)
I20260812 06:16:50.897917 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000006 (ops 26-30)
I20260812 06:16:50.897933 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000007 (ops 31-35)
I20260812 06:16:50.898000 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000008 (ops 36-40)
I20260812 06:16:50.898049 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000009 (ops 41-45)
I20260812 06:16:50.898132 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000010 (ops 46-50)
I20260812 06:16:50.898205 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000011 (ops 51-55)
I20260812 06:16:50.898255 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000012 (ops 56-60)
I20260812 06:16:50.898298 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000013 (ops 61-65)
I20260812 06:16:50.923702 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: LogGCOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:16:50.924547 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:50.953089 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.028s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4744,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.953650 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:50.968904 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5839,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:50.969501 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:51.234798 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.265s	user 0.151s	sys 0.108s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979853,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1347,"lbm_read_time_us":17861,"lbm_reads_lt_1ms":775,"lbm_write_time_us":40247,"lbm_writes_lt_1ms":743,"mutex_wait_us":823,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":102,"threads_started":1,"update_count":3500}
I20260812 06:16:51.235733 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=18.063937
I20260812 06:16:51.312187 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.076s	user 0.048s	sys 0.019s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":31257,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:51.312721 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:51.324836 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4184,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:51.325582 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:51.562597 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.237s	user 0.168s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":729,"lbm_read_time_us":14151,"lbm_reads_lt_1ms":672,"lbm_write_time_us":40308,"lbm_writes_lt_1ms":643,"mutex_wait_us":341,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":3000}
I20260812 06:16:51.563247 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=15.087375
I20260812 06:16:51.619913 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.056s	user 0.043s	sys 0.012s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":25392,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:16:51.620822 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:51.642608 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.022s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4987,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:51.643299 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:51.836834 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.193s	user 0.140s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":304,"lbm_read_time_us":12944,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34081,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:16:51.837631 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=14.095187
I20260812 06:16:51.894600 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.057s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20352,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:51.895304 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:51.916230 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.021s	user 0.006s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5412,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:51.916813 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:52.120898 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.204s	user 0.116s	sys 0.086s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":622,"lbm_read_time_us":13098,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34212,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:16:52.121762 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=14.095187
I20260812 06:16:52.183220 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.061s	user 0.038s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22173,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:52.183779 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:52.202382 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.018s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4563,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.202977 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:52.215396 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.012s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4472,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.216172 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:52.455704 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.239s	user 0.162s	sys 0.068s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":211,"lbm_read_time_us":16604,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36189,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":24064,"update_count":3000}
I20260812 06:16:52.456534 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=18.063937
I20260812 06:16:52.537351 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.081s	user 0.045s	sys 0.024s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":32011,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:52.537902 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:52.550345 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3856,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.550981 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushMRSOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:52.582721 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushMRSOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.032s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":197,"dirs.run_wall_time_us":1555,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1517,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:52.583436 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling LogGCOp(826067df6bc040a0ad85fe9fc0cba0ba): free 128867497 bytes of WAL
I20260812 06:16:52.583659 31558 log_reader.cc:385] T 826067df6bc040a0ad85fe9fc0cba0ba: removed 13 log segments from log reader
I20260812 06:16:52.583729 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000014 (ops 66-70)
I20260812 06:16:52.583784 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000015 (ops 71-74)
I20260812 06:16:52.583840 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000016 (ops 75-79)
I20260812 06:16:52.583884 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000017 (ops 80-84)
I20260812 06:16:52.583915 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000018 (ops 85-88)
I20260812 06:16:52.583950 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000019 (ops 89-93)
I20260812 06:16:52.583985 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000020 (ops 94-98)
I20260812 06:16:52.584022 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000021 (ops 99-102)
I20260812 06:16:52.584060 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000022 (ops 103-107)
I20260812 06:16:52.584097 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000023 (ops 108-112)
I20260812 06:16:52.584133 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000024 (ops 113-117)
I20260812 06:16:52.584169 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000025 (ops 118-122)
I20260812 06:16:52.584208 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000026 (ops 123-127)
I20260812 06:16:52.612931 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: LogGCOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:16:52.613651 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling UndoDeltaBlockGCOp(826067df6bc040a0ad85fe9fc0cba0ba): 472 bytes on disk
I20260812 06:16:52.614332 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: UndoDeltaBlockGCOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:16:52.615284 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=3.181125
I20260812 06:16:52.637998 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.023s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7879,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:52.638496 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:52.649439 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4116,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:52.649945 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:52.915364 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.265s	user 0.165s	sys 0.100s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082155,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1454,"lbm_read_time_us":19376,"lbm_reads_lt_1ms":874,"lbm_write_time_us":48101,"lbm_writes_lt_1ms":843,"mutex_wait_us":371,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":8448,"thread_start_us":80,"threads_started":1,"update_count":4000}
I20260812 06:16:52.916579 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=18.063937
I20260812 06:16:52.999697 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.083s	user 0.030s	sys 0.044s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":31639,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:53.000219 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=6.157687
I20260812 06:16:53.033953 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.033s	user 0.018s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":13794,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":202,"reinsert_count":0,"update_count":1000}
I20260812 06:16:53.035183 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:53.238629 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.203s	user 0.153s	sys 0.049s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979518,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2020,"lbm_read_time_us":15668,"lbm_reads_lt_1ms":764,"lbm_write_time_us":41848,"lbm_writes_lt_1ms":743,"mutex_wait_us":50,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":3500}
I20260812 06:16:53.239672 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=15.087375
I20260812 06:16:53.292186 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.052s	user 0.027s	sys 0.024s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":23281,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:16:53.292744 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:53.307265 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5953,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:53.307775 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:53.472774 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.165s	user 0.129s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":407,"lbm_read_time_us":12177,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30522,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:16:53.473493 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=10.126437
I20260812 06:16:53.521020 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.047s	user 0.013s	sys 0.031s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20353,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.521736 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:53.538904 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.017s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6076,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.539435 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:53.702569 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.163s	user 0.089s	sys 0.059s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":8898,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26887,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:53.703182 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=14.095187
I20260812 06:16:53.776324 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.073s	user 0.031s	sys 0.032s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21917,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:53.777185 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:53.789472 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4753,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.790103 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:53.975183 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.185s	user 0.105s	sys 0.077s 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":949,"lbm_read_time_us":14047,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30265,"lbm_writes_lt_1ms":543,"mutex_wait_us":558,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:16:53.975736 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=11.118625
I20260812 06:16:54.027483 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.052s	user 0.029s	sys 0.021s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":24029,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:16:54.028036 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:54.049166 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.021s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4649,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.049773 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:54.062438 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4646,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:54.063434 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushMRSOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:54.103565 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushMRSOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.040s	user 0.024s	sys 0.005s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":206,"dirs.run_wall_time_us":1798,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1923,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:54.104483 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling LogGCOp(826067df6bc040a0ad85fe9fc0cba0ba): free 112692610 bytes of WAL
I20260812 06:16:54.105106 31558 log_reader.cc:385] T 826067df6bc040a0ad85fe9fc0cba0ba: removed 11 log segments from log reader
I20260812 06:16:54.105213 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000027 (ops 128-132)
I20260812 06:16:54.105265 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000028 (ops 133-137)
I20260812 06:16:54.105310 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000029 (ops 138-142)
I20260812 06:16:54.105333 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000030 (ops 143-147)
I20260812 06:16:54.105394 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000031 (ops 148-152)
I20260812 06:16:54.105432 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000032 (ops 153-157)
I20260812 06:16:54.105464 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000033 (ops 158-162)
I20260812 06:16:54.105509 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000034 (ops 163-167)
I20260812 06:16:54.105558 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000035 (ops 168-172)
I20260812 06:16:54.105602 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000036 (ops 173-177)
I20260812 06:16:54.105650 31558 log.cc:1079] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: Deleting log segment in path: /tmp/dist-test-taskV5kbvT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515402653915-31221-0/minicluster-data/ts-0-root/wals/826067df6bc040a0ad85fe9fc0cba0ba/wal-000000037 (ops 178-182)
I20260812 06:16:54.130363 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: LogGCOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:16:54.130800 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling UndoDeltaBlockGCOp(826067df6bc040a0ad85fe9fc0cba0ba): 448 bytes on disk
I20260812 06:16:54.131309 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: UndoDeltaBlockGCOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:16:54.131855 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:54.159159 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.027s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6572,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.159698 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:54.172276 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4626,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.173028 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:54.427898 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.255s	user 0.174s	sys 0.080s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979861,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":403,"lbm_read_time_us":18061,"lbm_reads_lt_1ms":775,"lbm_write_time_us":43730,"lbm_writes_lt_1ms":743,"mutex_wait_us":60,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18176,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:16:54.429507 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=16.079562
I20260812 06:16:54.490869 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.061s	user 0.029s	sys 0.024s Metrics: {"bytes_written":17927795,"delete_count":0,"lbm_write_time_us":25701,"lbm_writes_lt_1ms":440,"reinsert_count":0,"update_count":2185}
I20260812 06:16:54.491830 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.196750
I20260812 06:16:54.504135 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":2994984,"delete_count":0,"lbm_write_time_us":3321,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:16:54.504647 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=2.188937
I20260812 06:16:54.514712 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: FlushDeltaMemStoresOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3740,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:54.515251 31633 maintenance_manager.cc:419] P b0b4fbf5e84149b99ef0a787c7539227: Scheduling MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba): perf score=1.000000
I20260812 06:16:54.622018 31221 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.437s	user 2.012s	sys 0.168s
I20260812 06:16:54.702461 31221 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.080s	user 0.001s	sys 0.000s
I20260812 06:16:54.703110 31221 tablet_server.cc:179] TabletServer@127.30.125.65:0 shutting down...
I20260812 06:16:54.713734 31558 maintenance_manager.cc:643] P b0b4fbf5e84149b99ef0a787c7539227: MajorDeltaCompactionOp(826067df6bc040a0ad85fe9fc0cba0ba) complete. Timing: real 0.198s	user 0.125s	sys 0.073s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877184,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":708,"lbm_read_time_us":15281,"lbm_reads_lt_1ms":669,"lbm_write_time_us":35259,"lbm_writes_lt_1ms":643,"mutex_wait_us":114,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":3000}
I20260812 06:16:54.717166 31221 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:54.717553 31221 tablet_replica.cc:333] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227: stopping tablet replica
I20260812 06:16:54.717744 31221 raft_consensus.cc:2243] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:54.728977 31221 raft_consensus.cc:2272] T 826067df6bc040a0ad85fe9fc0cba0ba P b0b4fbf5e84149b99ef0a787c7539227 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:54.735152 31221 tablet_server.cc:196] TabletServer@127.30.125.65:0 shutdown complete.
I20260812 06:16:54.769179 31221 master.cc:562] Master@127.30.125.126:38993 shutting down...
I20260812 06:16:54.774089 31221 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:54.774390 31221 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:54.774458 31221 tablet_replica.cc:333] T 00000000000000000000000000000000 P a8ec07c871344c3b8a0228f6b975ab57: stopping tablet replica
I20260812 06:16:54.787921 31221 master.cc:584] Master@127.30.125.126:38993 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5922 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12213 ms total)

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