[==========] 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:19:13.070765 16103 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.185.254:41311
I20260812 06:19:13.071647 16103 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:19:13.072186 16103 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:13.078172 16112 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:19:13.078186 16113 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:19:13.078393 16103 server_base.cc:1061] running on GCE node
W20260812 06:19:13.078439 16115 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:19:13.078886 16103 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:13.078977 16103 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:19:13.079044 16103 hybrid_clock.cc:648] HybridClock initialized: now 1786515553079041 us; error 0 us; skew 500 ppm
I20260812 06:19:13.080830 16103 webserver.cc:533] Webserver started at http://127.15.185.254:36045/ using document root <none> and password file <none>
I20260812 06:19:13.081355 16103 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:13.081415 16103 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:13.081679 16103 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:13.083261 16103 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/master-0-root/instance:
uuid: "a6bacfd6b589494293bf451bee47d3c3"
format_stamp: "Formatted at 2026-08-12 06:19:13 on dist-test-slave-x5fp"
I20260812 06:19:13.086750 16103 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:13.089028 16121 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:19:13.090235 16103 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:19:13.090409 16103 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/master-0-root
uuid: "a6bacfd6b589494293bf451bee47d3c3"
format_stamp: "Formatted at 2026-08-12 06:19:13 on dist-test-slave-x5fp"
I20260812 06:19:13.090538 16103 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-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:19:13.112869 16103 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:13.113631 16103 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:19:13.113864 16103 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:13.123140 16103 rpc_server.cc:307] RPC server started. Bound to: 127.15.185.254:41311
I20260812 06:19:13.123147 16209 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.185.254:41311 every 8 connection(s)
I20260812 06:19:13.125660 16211 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:19:13.131060 16211 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3: Bootstrap starting.
I20260812 06:19:13.133455 16211 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:13.134372 16211 log.cc:826] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:13.136133 16211 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3: No bootstrap required, opened a new log
I20260812 06:19:13.138876 16211 raft_consensus.cc:359] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6bacfd6b589494293bf451bee47d3c3" member_type: VOTER }
I20260812 06:19:13.139039 16211 raft_consensus.cc:385] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:13.139109 16211 raft_consensus.cc:740] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a6bacfd6b589494293bf451bee47d3c3, State: Initialized, Role: FOLLOWER
I20260812 06:19:13.139788 16211 consensus_queue.cc:260] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [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: "a6bacfd6b589494293bf451bee47d3c3" member_type: VOTER }
I20260812 06:19:13.139969 16211 raft_consensus.cc:399] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:13.140050 16211 raft_consensus.cc:493] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:13.140218 16211 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:13.141049 16211 raft_consensus.cc:515] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6bacfd6b589494293bf451bee47d3c3" member_type: VOTER }
I20260812 06:19:13.141498 16211 leader_election.cc:304] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [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: a6bacfd6b589494293bf451bee47d3c3; no voters: 
I20260812 06:19:13.141855 16211 leader_election.cc:290] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:13.141973 16215 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:13.142285 16215 raft_consensus.cc:697] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [term 1 LEADER]: Becoming Leader. State: Replica: a6bacfd6b589494293bf451bee47d3c3, State: Running, Role: LEADER
I20260812 06:19:13.142771 16215 consensus_queue.cc:237] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [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: "a6bacfd6b589494293bf451bee47d3c3" member_type: VOTER }
I20260812 06:19:13.142835 16211 sys_catalog.cc:565] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:13.144862 16218 sys_catalog.cc:455] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [sys.catalog]: SysCatalogTable state changed. Reason: New leader a6bacfd6b589494293bf451bee47d3c3. Latest consensus state: current_term: 1 leader_uuid: "a6bacfd6b589494293bf451bee47d3c3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6bacfd6b589494293bf451bee47d3c3" member_type: VOTER } }
I20260812 06:19:13.144991 16218 sys_catalog.cc:458] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:13.145233 16217 sys_catalog.cc:455] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a6bacfd6b589494293bf451bee47d3c3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6bacfd6b589494293bf451bee47d3c3" member_type: VOTER } }
I20260812 06:19:13.145313 16217 sys_catalog.cc:458] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:13.145391 16103 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:19:13.147447 16238 catalog_manager.cc:1594] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:13.147537 16238 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:13.147617 16237 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:13.148370 16237 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:13.152675 16237 catalog_manager.cc:1383] Generated new cluster ID: 0897c22b3e48461c930dec5386d8c01e
I20260812 06:19:13.152786 16237 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:13.172291 16237 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:13.173256 16237 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:13.180897 16237 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3: Generated new TSK 0
I20260812 06:19:13.181552 16237 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:13.210438 16103 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:13.213624 16246 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:19:13.213742 16253 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:19:13.213653 16250 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:19:13.213933 16103 server_base.cc:1061] running on GCE node
I20260812 06:19:13.214216 16103 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:13.214268 16103 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:19:13.214293 16103 hybrid_clock.cc:648] HybridClock initialized: now 1786515553214291 us; error 0 us; skew 500 ppm
I20260812 06:19:13.215267 16103 webserver.cc:533] Webserver started at http://127.15.185.193:43385/ using document root <none> and password file <none>
I20260812 06:19:13.215441 16103 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:13.215494 16103 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:13.215574 16103 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:13.216006 16103 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/instance:
uuid: "9f2d98220e78456593efd9967d5fffb7"
format_stamp: "Formatted at 2026-08-12 06:19:13 on dist-test-slave-x5fp"
I20260812 06:19:13.217839 16103 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:13.218983 16259 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:19:13.219332 16103 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:13.219440 16103 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root
uuid: "9f2d98220e78456593efd9967d5fffb7"
format_stamp: "Formatted at 2026-08-12 06:19:13 on dist-test-slave-x5fp"
I20260812 06:19:13.219534 16103 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-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:19:13.224483 16103 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:13.224969 16103 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:13.225471 16103 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:13.226308 16103 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:13.226380 16103 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:13.226456 16103 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:13.226508 16103 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:13.233319 16103 rpc_server.cc:307] RPC server started. Bound to: 127.15.185.193:45541
I20260812 06:19:13.233358 16383 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.185.193:45541 every 8 connection(s)
I20260812 06:19:13.245132 16384 heartbeater.cc:344] Connected to a master server at 127.15.185.254:41311
I20260812 06:19:13.245572 16384 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:13.246145 16384 heartbeater.cc:507] Master 127.15.185.254:41311 requested a full tablet report, sending...
I20260812 06:19:13.247625 16154 ts_manager.cc:194] Registered new tserver with Master: 9f2d98220e78456593efd9967d5fffb7 (127.15.185.193:45541)
I20260812 06:19:13.247756 16103 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013749118s
I20260812 06:19:13.248966 16154 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48344
I20260812 06:19:13.260248 16154 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48358:
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:19:13.274647 16314 tablet_service.cc:1511] Processing CreateTablet for tablet 981f65d7c8b045049f39dd697e36ba40 (DEFAULT_TABLE table=heavy-update-compaction-test [id=f0d2088fec2c48cda5f463862c44093e]), partition=
I20260812 06:19:13.275172 16314 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 981f65d7c8b045049f39dd697e36ba40. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:13.277522 16402 tablet_bootstrap.cc:492] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Bootstrap starting.
I20260812 06:19:13.278991 16402 tablet_bootstrap.cc:654] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:13.280097 16402 tablet_bootstrap.cc:492] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: No bootstrap required, opened a new log
I20260812 06:19:13.280220 16402 ts_tablet_manager.cc:1403] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:13.280680 16402 raft_consensus.cc:359] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9f2d98220e78456593efd9967d5fffb7" member_type: VOTER last_known_addr { host: "127.15.185.193" port: 45541 } }
I20260812 06:19:13.280867 16402 raft_consensus.cc:385] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:13.280920 16402 raft_consensus.cc:740] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9f2d98220e78456593efd9967d5fffb7, State: Initialized, Role: FOLLOWER
I20260812 06:19:13.281064 16402 consensus_queue.cc:260] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7 [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: "9f2d98220e78456593efd9967d5fffb7" member_type: VOTER last_known_addr { host: "127.15.185.193" port: 45541 } }
I20260812 06:19:13.281172 16402 raft_consensus.cc:399] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:13.281220 16402 raft_consensus.cc:493] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:13.281275 16402 raft_consensus.cc:3060] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:13.282047 16402 raft_consensus.cc:515] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9f2d98220e78456593efd9967d5fffb7" member_type: VOTER last_known_addr { host: "127.15.185.193" port: 45541 } }
I20260812 06:19:13.282217 16402 leader_election.cc:304] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7 [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: 9f2d98220e78456593efd9967d5fffb7; no voters: 
I20260812 06:19:13.282423 16402 leader_election.cc:290] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:13.282719 16406 raft_consensus.cc:2804] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:13.282799 16402 ts_tablet_manager.cc:1434] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:13.282919 16406 raft_consensus.cc:697] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7 [term 1 LEADER]: Becoming Leader. State: Replica: 9f2d98220e78456593efd9967d5fffb7, State: Running, Role: LEADER
I20260812 06:19:13.283211 16384 heartbeater.cc:499] Master 127.15.185.254:41311 was elected leader, sending a full tablet report...
I20260812 06:19:13.283556 16406 consensus_queue.cc:237] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7 [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: "9f2d98220e78456593efd9967d5fffb7" member_type: VOTER last_known_addr { host: "127.15.185.193" port: 45541 } }
I20260812 06:19:13.286398 16154 catalog_manager.cc:5719] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7 reported cstate change: term changed from 0 to 1, leader changed from <none> to 9f2d98220e78456593efd9967d5fffb7 (127.15.185.193). New cstate: current_term: 1 leader_uuid: "9f2d98220e78456593efd9967d5fffb7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9f2d98220e78456593efd9967d5fffb7" member_type: VOTER last_known_addr { host: "127.15.185.193" port: 45541 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:13.351502 16103 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.007s	sys 0.019s
I20260812 06:19:13.484484 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushMRSOp(981f65d7c8b045049f39dd697e36ba40): perf score=19.054940
I20260812 06:19:13.669003 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushMRSOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.184s	user 0.128s	sys 0.055s Metrics: {"bytes_written":13251052,"cfile_init":1,"compiler_manager_pool.queue_time_us":178,"delete_count":0,"dirs.queue_time_us":91,"dirs.run_cpu_time_us":276,"dirs.run_wall_time_us":825,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46056,"lbm_writes_lt_1ms":780,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":160384,"thread_start_us":112,"threads_started":1,"update_count":1615}
I20260812 06:19:13.670300 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling LogGCOp(981f65d7c8b045049f39dd697e36ba40): free 20743831 bytes of WAL
I20260812 06:19:13.670608 16272 log_reader.cc:385] T 981f65d7c8b045049f39dd697e36ba40: removed 2 log segments from log reader
I20260812 06:19:13.670679 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000001 (ops 1-6)
I20260812 06:19:13.670734 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000002 (ops 7-11)
I20260812 06:19:13.676287 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: LogGCOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.006s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:13.676613 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=5.165500
I20260812 06:19:13.705061 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.028s	user 0.020s	sys 0.008s Metrics: {"bytes_written":6687189,"delete_count":0,"lbm_write_time_us":9018,"lbm_writes_lt_1ms":166,"reinsert_count":0,"update_count":815}
I20260812 06:19:13.705760 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:13.876920 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.171s	user 0.126s	sys 0.045s Metrics: {"cfile_cache_miss":518,"cfile_cache_miss_bytes":24200363,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":625,"lbm_read_time_us":12487,"lbm_reads_lt_1ms":554,"lbm_write_time_us":27287,"lbm_writes_lt_1ms":529,"mutex_wait_us":23,"peak_mem_usage":60460642,"reinsert_count":0,"spinlock_wait_cycles":13952,"thread_start_us":337,"threads_started":5,"update_count":2430}
I20260812 06:19:13.877568 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling UndoDeltaBlockGCOp(981f65d7c8b045049f39dd697e36ba40): 16411393 bytes on disk
I20260812 06:19:13.878214 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: UndoDeltaBlockGCOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":90,"lbm_reads_lt_1ms":4}
I20260812 06:19:13.878830 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=11.118625
I20260812 06:19:13.923596 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.045s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12881836,"delete_count":0,"lbm_write_time_us":17798,"lbm_writes_lt_1ms":317,"reinsert_count":0,"update_count":1570}
I20260812 06:19:13.924126 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:13.939355 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5610,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.940006 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:14.076508 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.136s	user 0.112s	sys 0.024s Metrics: {"cfile_cache_miss":446,"cfile_cache_miss_bytes":21246623,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":215,"lbm_read_time_us":9464,"lbm_reads_lt_1ms":486,"lbm_write_time_us":27225,"lbm_writes_lt_1ms":457,"mutex_wait_us":25,"peak_mem_usage":52304202,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2070}
I20260812 06:19:14.077208 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=10.126437
I20260812 06:19:14.115737 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.038s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14780,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.116240 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:14.127040 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3987,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.127552 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:14.248899 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.121s	user 0.109s	sys 0.012s 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":600,"lbm_read_time_us":8327,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23921,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2000}
I20260812 06:19:14.249471 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=10.126437
I20260812 06:19:14.289812 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.040s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15300,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.290288 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:14.301160 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4232,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.301779 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:14.418227 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.116s	user 0.080s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":569,"lbm_read_time_us":8601,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22439,"lbm_writes_lt_1ms":443,"mutex_wait_us":104,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2000}
I20260812 06:19:14.418776 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=10.126437
I20260812 06:19:14.465724 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.047s	user 0.024s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14966,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.466358 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:14.483023 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6281,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.483582 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:14.628170 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.144s	user 0.104s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":236,"lbm_read_time_us":11575,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23728,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2000}
I20260812 06:19:14.628712 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=10.126437
I20260812 06:19:14.671089 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.042s	user 0.030s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16215,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.671595 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:14.682998 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4119,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.683650 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:14.819048 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.135s	user 0.106s	sys 0.028s 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":328,"lbm_read_time_us":9536,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27803,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":65792,"update_count":2000}
I20260812 06:19:14.819581 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=10.126437
I20260812 06:19:14.868399 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.049s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18304,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.868963 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:14.880185 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4134,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.880803 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushMRSOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:14.913831 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushMRSOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.033s	user 0.027s	sys 0.005s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1444,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2038,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:14.914594 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling LogGCOp(981f65d7c8b045049f39dd697e36ba40): free 120100394 bytes of WAL
I20260812 06:19:14.914839 16272 log_reader.cc:385] T 981f65d7c8b045049f39dd697e36ba40: removed 12 log segments from log reader
I20260812 06:19:14.914902 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000003 (ops 12-16)
I20260812 06:19:14.914958 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000004 (ops 17-21)
I20260812 06:19:14.914996 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000005 (ops 22-26)
I20260812 06:19:14.915037 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000006 (ops 27-30)
I20260812 06:19:14.915076 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000007 (ops 31-35)
I20260812 06:19:14.915115 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000008 (ops 36-40)
I20260812 06:19:14.915153 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000009 (ops 41-44)
I20260812 06:19:14.915194 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000010 (ops 45-49)
I20260812 06:19:14.915234 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000011 (ops 50-54)
I20260812 06:19:14.915273 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000012 (ops 55-59)
I20260812 06:19:14.915313 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000013 (ops 60-64)
I20260812 06:19:14.915350 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000014 (ops 65-68)
I20260812 06:19:14.942482 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: LogGCOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:14.942914 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling UndoDeltaBlockGCOp(981f65d7c8b045049f39dd697e36ba40): 462 bytes on disk
I20260812 06:19:14.943315 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: UndoDeltaBlockGCOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:14.943789 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=5.165500
I20260812 06:19:14.967475 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.024s	user 0.005s	sys 0.016s Metrics: {"bytes_written":7220497,"delete_count":0,"lbm_write_time_us":9458,"lbm_writes_lt_1ms":179,"reinsert_count":0,"update_count":880}
I20260812 06:19:14.968055 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:15.131290 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.163s	user 0.105s	sys 0.051s Metrics: {"cfile_cache_miss":609,"cfile_cache_miss_bytes":27892639,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1275,"lbm_read_time_us":10893,"lbm_reads_lt_1ms":645,"lbm_write_time_us":31723,"lbm_writes_lt_1ms":619,"mutex_wait_us":620,"peak_mem_usage":72476864,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":84,"threads_started":1,"update_count":2880}
I20260812 06:19:15.131970 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=15.087375
I20260812 06:19:15.189833 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.058s	user 0.027s	sys 0.024s Metrics: {"bytes_written":17394486,"delete_count":0,"lbm_write_time_us":23880,"lbm_writes_lt_1ms":427,"reinsert_count":0,"update_count":2120}
I20260812 06:19:15.190311 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:15.202661 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4034,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.203229 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:15.369050 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.166s	user 0.137s	sys 0.015s Metrics: {"cfile_cache_miss":556,"cfile_cache_miss_bytes":25759273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":216,"lbm_read_time_us":10909,"lbm_reads_lt_1ms":596,"lbm_write_time_us":31678,"lbm_writes_lt_1ms":567,"mutex_wait_us":64,"peak_mem_usage":66181508,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2620}
I20260812 06:19:15.369583 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=14.095187
I20260812 06:19:15.418135 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.048s	user 0.033s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19685,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.418782 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:15.575394 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.156s	user 0.117s	sys 0.035s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":3922,"lbm_read_time_us":9389,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26487,"lbm_writes_lt_1ms":443,"mutex_wait_us":2828,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:15.576238 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=11.118625
I20260812 06:19:15.619519 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.043s	user 0.006s	sys 0.034s Metrics: {"bytes_written":12963877,"delete_count":0,"lbm_write_time_us":15818,"lbm_writes_lt_1ms":319,"reinsert_count":0,"update_count":1580}
I20260812 06:19:15.620074 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:15.635752 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.015s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":4007,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:19:15.636157 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:15.645478 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.009s	user 0.001s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3538,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:15.645848 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:15.825897 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.180s	user 0.120s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774791,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":304,"lbm_read_time_us":12522,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30966,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:19:15.826594 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=14.095187
I20260812 06:19:15.888129 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.061s	user 0.045s	sys 0.010s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22351,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.888693 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:15.900028 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4401,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.900535 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:16.078820 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.178s	user 0.114s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":170,"lbm_read_time_us":12440,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30120,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:19:16.079556 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=10.126437
I20260812 06:19:16.119769 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.040s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":17872,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.120198 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:16.131166 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4225,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.131924 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:16.268932 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.137s	user 0.102s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":356,"lbm_read_time_us":8883,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24608,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24960,"update_count":2000}
I20260812 06:19:16.269460 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=10.126437
I20260812 06:19:16.314267 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.045s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15100,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.314824 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:16.325646 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3985,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.326437 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushMRSOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:16.356506 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushMRSOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":167,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1352,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1924,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:16.357483 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling LogGCOp(981f65d7c8b045049f39dd697e36ba40): free 121006396 bytes of WAL
I20260812 06:19:16.357762 16272 log_reader.cc:385] T 981f65d7c8b045049f39dd697e36ba40: removed 12 log segments from log reader
I20260812 06:19:16.357836 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000015 (ops 69-73)
I20260812 06:19:16.357892 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000016 (ops 74-78)
I20260812 06:19:16.357950 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000017 (ops 79-83)
I20260812 06:19:16.357995 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000018 (ops 84-88)
I20260812 06:19:16.358042 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000019 (ops 89-93)
I20260812 06:19:16.358083 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000020 (ops 94-98)
I20260812 06:19:16.358121 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000021 (ops 99-102)
I20260812 06:19:16.358160 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000022 (ops 103-107)
I20260812 06:19:16.358199 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000023 (ops 108-112)
I20260812 06:19:16.358238 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000024 (ops 113-117)
I20260812 06:19:16.358284 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000025 (ops 118-122)
I20260812 06:19:16.358323 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000026 (ops 123-127)
I20260812 06:19:16.385284 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: LogGCOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:16.385892 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling UndoDeltaBlockGCOp(981f65d7c8b045049f39dd697e36ba40): 462 bytes on disk
I20260812 06:19:16.386498 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: UndoDeltaBlockGCOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:19:16.387084 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=3.181125
I20260812 06:19:16.408916 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.022s	user 0.006s	sys 0.013s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":7224,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:16.409425 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:16.419226 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3492,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:16.419697 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:16.602059 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.182s	user 0.136s	sys 0.035s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1218,"lbm_read_time_us":11727,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37308,"lbm_writes_lt_1ms":643,"mutex_wait_us":568,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5120,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:19:16.603076 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=14.095187
I20260812 06:19:16.655845 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.053s	user 0.012s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21233,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.656291 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:16.667376 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3947,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.668027 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:16.840507 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.172s	user 0.126s	sys 0.033s 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":339,"lbm_read_time_us":10755,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31646,"lbm_writes_lt_1ms":543,"mutex_wait_us":69,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:19:16.841109 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=14.095187
I20260812 06:19:16.894923 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.054s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19552,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.895435 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:16.908221 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.013s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4118,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.908914 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:17.056982 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.148s	user 0.109s	sys 0.038s 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":198,"lbm_read_time_us":11463,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29291,"lbm_writes_lt_1ms":543,"mutex_wait_us":72,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2500}
I20260812 06:19:17.057682 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=11.118625
I20260812 06:19:17.091392 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.034s	user 0.017s	sys 0.014s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14515,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:17.091881 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:17.117417 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.025s	user 0.004s	sys 0.011s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":6203,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:19:17.117914 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:17.128412 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":4161,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:19:17.128898 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:17.279995 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.151s	user 0.116s	sys 0.026s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774803,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":137,"lbm_read_time_us":10403,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29898,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:17.280808 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=14.095187
I20260812 06:19:17.326889 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.046s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19406,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.327338 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:17.338661 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3984,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.339177 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:17.513357 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.174s	user 0.138s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":840,"lbm_read_time_us":11228,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35340,"lbm_writes_lt_1ms":543,"mutex_wait_us":329,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:17.514034 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=14.095187
I20260812 06:19:17.568238 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.054s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20425,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.568831 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=2.188937
I20260812 06:19:17.580660 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3994,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.581331 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:17.756304 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.175s	user 0.117s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":244,"lbm_read_time_us":12111,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30390,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":70400,"update_count":2500}
I20260812 06:19:17.757215 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=14.095187
I20260812 06:19:17.805016 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.048s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20992,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.805799 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushMRSOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:17.840826 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushMRSOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.035s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":190,"dirs.run_wall_time_us":2006,"drs_written":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1620,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:17.841861 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling LogGCOp(981f65d7c8b045049f39dd697e36ba40): free 120553692 bytes of WAL
I20260812 06:19:17.842183 16272 log_reader.cc:385] T 981f65d7c8b045049f39dd697e36ba40: removed 12 log segments from log reader
I20260812 06:19:17.842273 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000027 (ops 128-132)
I20260812 06:19:17.842319 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000028 (ops 133-137)
I20260812 06:19:17.842368 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000029 (ops 138-142)
I20260812 06:19:17.842397 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000030 (ops 143-147)
I20260812 06:19:17.842434 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000031 (ops 148-152)
I20260812 06:19:17.842469 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000032 (ops 153-156)
I20260812 06:19:17.842505 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000033 (ops 157-161)
I20260812 06:19:17.842540 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000034 (ops 162-166)
I20260812 06:19:17.842574 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000035 (ops 167-170)
I20260812 06:19:17.842609 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000036 (ops 171-175)
I20260812 06:19:17.842643 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000037 (ops 176-180)
I20260812 06:19:17.842676 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000038 (ops 181-185)
I20260812 06:19:17.868765 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: LogGCOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.027s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:17.869153 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=6.157687
I20260812 06:19:17.891834 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.023s	user 0.018s	sys 0.001s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8971,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:17.892379 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling LogGCOp(981f65d7c8b045049f39dd697e36ba40): free 8767143 bytes of WAL
I20260812 06:19:17.892591 16272 log_reader.cc:385] T 981f65d7c8b045049f39dd697e36ba40: removed 1 log segments from log reader
I20260812 06:19:17.892647 16272 log.cc:1079] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/981f65d7c8b045049f39dd697e36ba40/wal-000000039 (ops 186-190)
I20260812 06:19:17.894539 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: LogGCOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:17.894945 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:18.105083 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.210s	user 0.152s	sys 0.055s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":280,"lbm_read_time_us":16270,"lbm_reads_lt_1ms":664,"lbm_write_time_us":33166,"lbm_writes_lt_1ms":643,"mutex_wait_us":74,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1920,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:19:18.105890 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=16.079562
I20260812 06:19:18.118644 16103 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.767s	user 1.753s	sys 0.130s
I20260812 06:19:18.170140 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.064s	user 0.050s	sys 0.013s Metrics: {"bytes_written":18543157,"delete_count":0,"lbm_write_time_us":27889,"lbm_writes_lt_1ms":455,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2260}
I20260812 06:19:18.170810 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling UndoDeltaBlockGCOp(981f65d7c8b045049f39dd697e36ba40): 492 bytes on disk
I20260812 06:19:18.171268 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: UndoDeltaBlockGCOp(981f65d7c8b045049f39dd697e36ba40) 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:19:18.171826 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:18.176060 16103 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.057s	user 0.001s	sys 0.000s
I20260812 06:19:18.176648 16103 tablet_server.cc:179] TabletServer@127.15.185.193:0 shutting down...
I20260812 06:19:18.179937 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: FlushDeltaMemStoresOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.008s	user 0.000s	sys 0.006s Metrics: {"bytes_written":1969352,"delete_count":0,"lbm_write_time_us":2436,"lbm_writes_lt_1ms":51,"reinsert_count":0,"update_count":240}
I20260812 06:19:18.180445 16385 maintenance_manager.cc:419] P 9f2d98220e78456593efd9967d5fffb7: Scheduling MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40): perf score=1.000000
I20260812 06:19:18.317178 16272 maintenance_manager.cc:643] P 9f2d98220e78456593efd9967d5fffb7: MajorDeltaCompactionOp(981f65d7c8b045049f39dd697e36ba40) complete. Timing: real 0.137s	user 0.093s	sys 0.043s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":502,"cfile_cache_miss_bytes":20512248,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1364,"lbm_read_time_us":7384,"lbm_reads_lt_1ms":518,"lbm_write_time_us":24361,"lbm_writes_lt_1ms":543,"mutex_wait_us":309,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18176,"update_count":2500}
I20260812 06:19:18.317961 16103 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:18.318403 16103 tablet_replica.cc:333] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7: stopping tablet replica
I20260812 06:19:18.318638 16103 raft_consensus.cc:2243] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:18.318866 16103 raft_consensus.cc:2272] T 981f65d7c8b045049f39dd697e36ba40 P 9f2d98220e78456593efd9967d5fffb7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:18.334548 16103 tablet_server.cc:196] TabletServer@127.15.185.193:0 shutdown complete.
I20260812 06:19:18.363359 16103 master.cc:562] Master@127.15.185.254:41311 shutting down...
I20260812 06:19:18.366875 16103 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:18.367067 16103 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:18.367158 16103 tablet_replica.cc:333] T 00000000000000000000000000000000 P a6bacfd6b589494293bf451bee47d3c3: stopping tablet replica
I20260812 06:19:18.379608 16103 master.cc:584] Master@127.15.185.254:41311 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5402 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:18.472618 16103 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.185.254:34309
I20260812 06:19:18.473084 16103 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:18.475253 16438 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:19:18.475267 16437 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:19:18.475358 16444 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:19:18.475464 16103 server_base.cc:1061] running on GCE node
I20260812 06:19:18.475744 16103 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:18.475791 16103 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:19:18.475806 16103 hybrid_clock.cc:648] HybridClock initialized: now 1786515558475807 us; error 0 us; skew 500 ppm
I20260812 06:19:18.476859 16103 webserver.cc:533] Webserver started at http://127.15.185.254:39237/ using document root <none> and password file <none>
I20260812 06:19:18.477013 16103 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:18.477061 16103 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:18.477113 16103 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:18.477448 16103 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/master-0-root/instance:
uuid: "d77e343fb1aa47c29bdd6d8b7fd21016"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-x5fp"
I20260812 06:19:18.479275 16103 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:18.480202 16450 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:19:18.480425 16103 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:18.480490 16103 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/master-0-root
uuid: "d77e343fb1aa47c29bdd6d8b7fd21016"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-x5fp"
I20260812 06:19:18.480548 16103 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-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:19:18.505225 16103 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:18.505636 16103 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:18.509943 16103 rpc_server.cc:307] RPC server started. Bound to: 127.15.185.254:34309
I20260812 06:19:18.513928 16537 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.185.254:34309 every 8 connection(s)
I20260812 06:19:18.515218 16543 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:19:18.528342 16543 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016: Bootstrap starting.
I20260812 06:19:18.529234 16543 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:18.530397 16543 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016: No bootstrap required, opened a new log
I20260812 06:19:18.530789 16543 raft_consensus.cc:359] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d77e343fb1aa47c29bdd6d8b7fd21016" member_type: VOTER }
I20260812 06:19:18.530906 16543 raft_consensus.cc:385] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:18.530931 16543 raft_consensus.cc:740] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d77e343fb1aa47c29bdd6d8b7fd21016, State: Initialized, Role: FOLLOWER
I20260812 06:19:18.531045 16543 consensus_queue.cc:260] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [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: "d77e343fb1aa47c29bdd6d8b7fd21016" member_type: VOTER }
I20260812 06:19:18.531104 16543 raft_consensus.cc:399] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:18.531126 16543 raft_consensus.cc:493] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:18.531162 16543 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:18.531864 16543 raft_consensus.cc:515] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d77e343fb1aa47c29bdd6d8b7fd21016" member_type: VOTER }
I20260812 06:19:18.531986 16543 leader_election.cc:304] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [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: d77e343fb1aa47c29bdd6d8b7fd21016; no voters: 
I20260812 06:19:18.532157 16543 leader_election.cc:290] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:18.532335 16546 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:18.532559 16546 raft_consensus.cc:697] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [term 1 LEADER]: Becoming Leader. State: Replica: d77e343fb1aa47c29bdd6d8b7fd21016, State: Running, Role: LEADER
I20260812 06:19:18.532645 16543 sys_catalog.cc:565] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:18.532804 16546 consensus_queue.cc:237] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [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: "d77e343fb1aa47c29bdd6d8b7fd21016" member_type: VOTER }
I20260812 06:19:18.533295 16550 sys_catalog.cc:455] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d77e343fb1aa47c29bdd6d8b7fd21016" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d77e343fb1aa47c29bdd6d8b7fd21016" member_type: VOTER } }
I20260812 06:19:18.533344 16551 sys_catalog.cc:455] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [sys.catalog]: SysCatalogTable state changed. Reason: New leader d77e343fb1aa47c29bdd6d8b7fd21016. Latest consensus state: current_term: 1 leader_uuid: "d77e343fb1aa47c29bdd6d8b7fd21016" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d77e343fb1aa47c29bdd6d8b7fd21016" member_type: VOTER } }
I20260812 06:19:18.533413 16550 sys_catalog.cc:458] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:18.533432 16551 sys_catalog.cc:458] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:18.533964 16556 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:18.534653 16556 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:18.534847 16103 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:18.536577 16556 catalog_manager.cc:1383] Generated new cluster ID: 3abe290f959e451086d6d8d84d77fde4
I20260812 06:19:18.536659 16556 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:18.555413 16556 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:18.556041 16556 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:18.563683 16556 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016: Generated new TSK 0
I20260812 06:19:18.563884 16556 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:18.567312 16103 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:18.569367 16571 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:19:18.569419 16574 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:19:18.569422 16569 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:19:18.569531 16103 server_base.cc:1061] running on GCE node
I20260812 06:19:18.569748 16103 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:18.569794 16103 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:19:18.569810 16103 hybrid_clock.cc:648] HybridClock initialized: now 1786515558569810 us; error 0 us; skew 500 ppm
I20260812 06:19:18.570673 16103 webserver.cc:533] Webserver started at http://127.15.185.193:38281/ using document root <none> and password file <none>
I20260812 06:19:18.570840 16103 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:18.570930 16103 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:18.571031 16103 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:18.571424 16103 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/instance:
uuid: "45591522918945d5a6c3df3eca6ddf71"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-x5fp"
I20260812 06:19:18.572976 16103 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:18.573983 16582 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:19:18.574249 16103 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:18.574316 16103 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root
uuid: "45591522918945d5a6c3df3eca6ddf71"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-x5fp"
I20260812 06:19:18.574407 16103 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-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:19:18.594491 16103 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:18.594941 16103 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:18.595265 16103 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:18.595759 16103 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:18.595798 16103 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.595865 16103 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:18.595906 16103 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.600178 16103 rpc_server.cc:307] RPC server started. Bound to: 127.15.185.193:39953
I20260812 06:19:18.600212 16676 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.185.193:39953 every 8 connection(s)
I20260812 06:19:18.609777 16678 heartbeater.cc:344] Connected to a master server at 127.15.185.254:34309
I20260812 06:19:18.609892 16678 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:18.610088 16678 heartbeater.cc:507] Master 127.15.185.254:34309 requested a full tablet report, sending...
I20260812 06:19:18.610733 16481 ts_manager.cc:194] Registered new tserver with Master: 45591522918945d5a6c3df3eca6ddf71 (127.15.185.193:39953)
I20260812 06:19:18.611495 16481 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:35298
I20260812 06:19:18.611591 16103 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011014559s
I20260812 06:19:18.618961 16481 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:35302:
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:19:18.628289 16625 tablet_service.cc:1511] Processing CreateTablet for tablet aac2313b28e7462bbb788ad7249e01eb (DEFAULT_TABLE table=heavy-update-compaction-test [id=f64ca9d4653344beb59704ad73303942]), partition=
I20260812 06:19:18.628623 16625 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet aac2313b28e7462bbb788ad7249e01eb. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:18.630822 16698 tablet_bootstrap.cc:492] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Bootstrap starting.
I20260812 06:19:18.631716 16698 tablet_bootstrap.cc:654] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:18.632912 16698 tablet_bootstrap.cc:492] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: No bootstrap required, opened a new log
I20260812 06:19:18.632990 16698 ts_tablet_manager.cc:1403] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:18.633601 16698 raft_consensus.cc:359] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "45591522918945d5a6c3df3eca6ddf71" member_type: VOTER last_known_addr { host: "127.15.185.193" port: 39953 } }
I20260812 06:19:18.633811 16698 raft_consensus.cc:385] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:18.633869 16698 raft_consensus.cc:740] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 45591522918945d5a6c3df3eca6ddf71, State: Initialized, Role: FOLLOWER
I20260812 06:19:18.634022 16698 consensus_queue.cc:260] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71 [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: "45591522918945d5a6c3df3eca6ddf71" member_type: VOTER last_known_addr { host: "127.15.185.193" port: 39953 } }
I20260812 06:19:18.634114 16698 raft_consensus.cc:399] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:18.634140 16698 raft_consensus.cc:493] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:18.634169 16698 raft_consensus.cc:3060] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:18.634922 16698 raft_consensus.cc:515] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "45591522918945d5a6c3df3eca6ddf71" member_type: VOTER last_known_addr { host: "127.15.185.193" port: 39953 } }
I20260812 06:19:18.635066 16698 leader_election.cc:304] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71 [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: 45591522918945d5a6c3df3eca6ddf71; no voters: 
I20260812 06:19:18.635303 16698 leader_election.cc:290] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:18.635461 16700 raft_consensus.cc:2804] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:18.635670 16678 heartbeater.cc:499] Master 127.15.185.254:34309 was elected leader, sending a full tablet report...
I20260812 06:19:18.635680 16698 ts_tablet_manager.cc:1434] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:18.635689 16700 raft_consensus.cc:697] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71 [term 1 LEADER]: Becoming Leader. State: Replica: 45591522918945d5a6c3df3eca6ddf71, State: Running, Role: LEADER
I20260812 06:19:18.635897 16700 consensus_queue.cc:237] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71 [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: "45591522918945d5a6c3df3eca6ddf71" member_type: VOTER last_known_addr { host: "127.15.185.193" port: 39953 } }
I20260812 06:19:18.637269 16481 catalog_manager.cc:5719] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71 reported cstate change: term changed from 0 to 1, leader changed from <none> to 45591522918945d5a6c3df3eca6ddf71 (127.15.185.193). New cstate: current_term: 1 leader_uuid: "45591522918945d5a6c3df3eca6ddf71" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "45591522918945d5a6c3df3eca6ddf71" member_type: VOTER last_known_addr { host: "127.15.185.193" port: 39953 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:18.695209 16103 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.014s	sys 0.008s
I20260812 06:19:18.851130 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushMRSOp(aac2313b28e7462bbb788ad7249e01eb): perf score=19.054940
I20260812 06:19:18.999501 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushMRSOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.148s	user 0.121s	sys 0.024s Metrics: {"bytes_written":12799771,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":273,"dirs.run_wall_time_us":1113,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36796,"lbm_writes_lt_1ms":769,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":3328,"update_count":1560}
I20260812 06:19:19.000321 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling LogGCOp(aac2313b28e7462bbb788ad7249e01eb): free 20290830 bytes of WAL
I20260812 06:19:19.000620 16589 log_reader.cc:385] T aac2313b28e7462bbb788ad7249e01eb: removed 2 log segments from log reader
I20260812 06:19:19.000694 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000001 (ops 1-6)
I20260812 06:19:19.000847 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000002 (ops 7-10)
I20260812 06:19:19.006412 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: LogGCOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:19:19.006788 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling UndoDeltaBlockGCOp(aac2313b28e7462bbb788ad7249e01eb): 16411393 bytes on disk
I20260812 06:19:19.007417 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: UndoDeltaBlockGCOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:19.007891 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:19.019311 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":3941,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:19:19.019723 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:19.028999 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3522,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:19.029392 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:19.198370 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.169s	user 0.135s	sys 0.027s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774785,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":513,"lbm_read_time_us":14311,"lbm_reads_lt_1ms":569,"lbm_write_time_us":26765,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6144,"thread_start_us":320,"threads_started":5,"update_count":2500}
I20260812 06:19:19.198890 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=14.095187
I20260812 06:19:19.248194 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.049s	user 0.036s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19134,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.248653 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:19.259406 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3880,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.259999 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:19.417874 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.158s	user 0.138s	sys 0.016s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":577,"lbm_read_time_us":9883,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29944,"lbm_writes_lt_1ms":543,"mutex_wait_us":306,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:19:19.418363 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=14.095187
I20260812 06:19:19.481670 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.063s	user 0.047s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23949,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.482347 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:19.499420 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.017s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6830,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.499856 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:19.648635 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.149s	user 0.122s	sys 0.024s 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":572,"lbm_read_time_us":10196,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30160,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18688,"update_count":2500}
I20260812 06:19:19.649132 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=14.095187
I20260812 06:19:19.702919 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.054s	user 0.024s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23461,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.703480 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:19.719048 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.015s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5680,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.720119 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:19.884567 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.164s	user 0.120s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":929,"lbm_read_time_us":11683,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32367,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2500}
I20260812 06:19:19.885102 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=14.095187
I20260812 06:19:19.945572 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.060s	user 0.024s	sys 0.027s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":23526,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.946066 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:19.957022 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3983,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.957665 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:20.120524 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.163s	user 0.119s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":620,"lbm_read_time_us":11491,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29663,"lbm_writes_lt_1ms":543,"mutex_wait_us":322,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24448,"update_count":2500}
I20260812 06:19:20.121256 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=14.095187
I20260812 06:19:20.175540 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.054s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20955,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.176031 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:20.186818 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.011s	user 0.001s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4062,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.187420 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushMRSOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:20.220080 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushMRSOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":1378,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1394,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:20.220645 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling LogGCOp(aac2313b28e7462bbb788ad7249e01eb): free 124710296 bytes of WAL
I20260812 06:19:20.220885 16589 log_reader.cc:385] T aac2313b28e7462bbb788ad7249e01eb: removed 12 log segments from log reader
I20260812 06:19:20.220949 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000003 (ops 11-15)
I20260812 06:19:20.221004 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000004 (ops 16-20)
I20260812 06:19:20.221061 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000005 (ops 21-25)
I20260812 06:19:20.221103 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000006 (ops 26-30)
I20260812 06:19:20.221139 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000007 (ops 31-35)
I20260812 06:19:20.221175 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000008 (ops 36-40)
I20260812 06:19:20.221212 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000009 (ops 41-45)
I20260812 06:19:20.221249 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000010 (ops 46-50)
I20260812 06:19:20.221292 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000011 (ops 51-55)
I20260812 06:19:20.221328 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000012 (ops 56-60)
I20260812 06:19:20.221364 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000013 (ops 61-65)
I20260812 06:19:20.221398 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000014 (ops 66-70)
I20260812 06:19:20.249027 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: LogGCOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.028s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:20.249388 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=3.181125
I20260812 06:19:20.260993 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4718026,"delete_count":0,"lbm_write_time_us":4479,"lbm_writes_lt_1ms":118,"reinsert_count":0,"update_count":575}
I20260812 06:19:20.261399 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:20.270557 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3487280,"delete_count":0,"lbm_write_time_us":3288,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:19:20.271112 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling UndoDeltaBlockGCOp(aac2313b28e7462bbb788ad7249e01eb): 472 bytes on disk
I20260812 06:19:20.271612 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: UndoDeltaBlockGCOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:19:20.272164 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:20.492549 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.220s	user 0.130s	sys 0.085s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979738,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":769,"lbm_read_time_us":16402,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37318,"lbm_writes_lt_1ms":743,"mutex_wait_us":48,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7424,"thread_start_us":90,"threads_started":1,"update_count":3500}
I20260812 06:19:20.493093 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=18.063937
I20260812 06:19:20.550855 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.058s	user 0.036s	sys 0.019s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25966,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:20.551412 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:20.567955 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6521,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.568459 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:20.732782 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.164s	user 0.108s	sys 0.055s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":555,"lbm_read_time_us":12748,"lbm_reads_lt_1ms":668,"lbm_write_time_us":32826,"lbm_writes_lt_1ms":643,"mutex_wait_us":40,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:19:20.733579 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=14.095187
I20260812 06:19:20.782755 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.049s	user 0.043s	sys 0.004s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21518,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.783463 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:20.796324 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4958,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.797041 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:20.968219 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.171s	user 0.107s	sys 0.053s 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":405,"lbm_read_time_us":10991,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30910,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:19:20.969080 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=14.095187
I20260812 06:19:21.030627 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.061s	user 0.032s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22363,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.031126 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:21.042295 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4045,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.043113 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:21.285112 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.242s	user 0.168s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":5106,"lbm_read_time_us":12520,"lbm_reads_lt_1ms":572,"lbm_write_time_us":38689,"lbm_writes_lt_1ms":543,"mutex_wait_us":3848,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:19:21.286357 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=18.063937
I20260812 06:19:21.358947 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.072s	user 0.054s	sys 0.016s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":32648,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:21.359494 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:21.369971 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3962,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.370432 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:21.587605 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.217s	user 0.133s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1169,"lbm_read_time_us":16544,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33248,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":3000}
I20260812 06:19:21.588276 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=18.063937
I20260812 06:19:21.658259 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.070s	user 0.038s	sys 0.016s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":24984,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:21.658710 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:21.670011 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4015,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.670665 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushMRSOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:21.702837 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushMRSOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.032s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":1392,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2021,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:21.703480 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling LogGCOp(aac2313b28e7462bbb788ad7249e01eb): free 117302581 bytes of WAL
I20260812 06:19:21.703737 16589 log_reader.cc:385] T aac2313b28e7462bbb788ad7249e01eb: removed 12 log segments from log reader
I20260812 06:19:21.703799 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000015 (ops 71-75)
I20260812 06:19:21.703840 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000016 (ops 76-80)
I20260812 06:19:21.703876 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000017 (ops 81-85)
I20260812 06:19:21.703899 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000018 (ops 86-90)
I20260812 06:19:21.703922 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000019 (ops 91-94)
I20260812 06:19:21.703949 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000020 (ops 95-99)
I20260812 06:19:21.703974 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000021 (ops 100-104)
I20260812 06:19:21.704007 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000022 (ops 105-108)
I20260812 06:19:21.704036 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000023 (ops 109-113)
I20260812 06:19:21.704062 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000024 (ops 114-118)
I20260812 06:19:21.704088 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000025 (ops 119-123)
I20260812 06:19:21.704115 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000026 (ops 124-128)
I20260812 06:19:21.735059 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: LogGCOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:21.735491 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling UndoDeltaBlockGCOp(aac2313b28e7462bbb788ad7249e01eb): 472 bytes on disk
I20260812 06:19:21.736052 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: UndoDeltaBlockGCOp(aac2313b28e7462bbb788ad7249e01eb) 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:19:21.736630 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:21.758395 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.022s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5319,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.758841 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:21.769063 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3962,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.769467 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:22.008533 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.239s	user 0.183s	sys 0.056s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082164,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":222,"lbm_read_time_us":16903,"lbm_reads_lt_1ms":874,"lbm_write_time_us":43952,"lbm_writes_lt_1ms":843,"mutex_wait_us":23,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":16256,"thread_start_us":80,"threads_started":1,"update_count":4000}
I20260812 06:19:22.009284 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=18.063937
I20260812 06:19:22.059213 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.049s	user 0.035s	sys 0.011s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":22124,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:22.059703 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:22.079809 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.020s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5303,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.080363 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:22.244791 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.164s	user 0.127s	sys 0.034s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":659,"lbm_read_time_us":11120,"lbm_reads_lt_1ms":664,"lbm_write_time_us":33217,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":3000}
I20260812 06:19:22.245491 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=15.087375
I20260812 06:19:22.299849 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.054s	user 0.022s	sys 0.028s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":24043,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":411,"reinsert_count":0,"update_count":2050}
I20260812 06:19:22.300489 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:22.322281 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.022s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6312,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.322748 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:22.332317 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3522,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:22.332870 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:22.501967 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.169s	user 0.136s	sys 0.032s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877208,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":307,"lbm_read_time_us":12182,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33853,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":3000}
I20260812 06:19:22.502831 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=14.095187
I20260812 06:19:22.545329 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.042s	user 0.030s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18238,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.545887 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:22.564836 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.019s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5414,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.565282 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:22.720916 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.155s	user 0.109s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":4013,"lbm_read_time_us":10139,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28324,"lbm_writes_lt_1ms":543,"mutex_wait_us":3443,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:19:22.721525 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=14.095187
I20260812 06:19:22.762718 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.041s	user 0.023s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18483,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.763257 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:22.920468 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.157s	user 0.100s	sys 0.052s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":178,"lbm_read_time_us":12230,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23531,"lbm_writes_lt_1ms":443,"mutex_wait_us":74,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2000}
I20260812 06:19:22.921312 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=14.095187
I20260812 06:19:22.969170 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.048s	user 0.037s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19965,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.969678 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:22.981335 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4108,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.981997 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushMRSOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:23.019482 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushMRSOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.037s	user 0.031s	sys 0.003s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":1365,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1669,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:23.020290 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling LogGCOp(aac2313b28e7462bbb788ad7249e01eb): free 124257449 bytes of WAL
I20260812 06:19:23.020576 16589 log_reader.cc:385] T aac2313b28e7462bbb788ad7249e01eb: removed 12 log segments from log reader
I20260812 06:19:23.020644 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000027 (ops 129-133)
I20260812 06:19:23.020685 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000028 (ops 134-138)
I20260812 06:19:23.020761 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000029 (ops 139-143)
I20260812 06:19:23.020818 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000030 (ops 144-148)
I20260812 06:19:23.020844 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000031 (ops 149-153)
I20260812 06:19:23.020879 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000032 (ops 154-158)
I20260812 06:19:23.020911 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000033 (ops 159-163)
I20260812 06:19:23.020943 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000034 (ops 164-168)
I20260812 06:19:23.020982 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000035 (ops 169-172)
I20260812 06:19:23.021018 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000036 (ops 173-177)
I20260812 06:19:23.021050 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000037 (ops 178-182)
I20260812 06:19:23.021081 16589 log.cc:1079] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: Deleting log segment in path: /tmp/dist-test-taskp0NklW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553060492-16103-0/minicluster-data/ts-0-root/wals/aac2313b28e7462bbb788ad7249e01eb/wal-000000038 (ops 183-187)
I20260812 06:19:23.057039 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: LogGCOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.037s	user 0.001s	sys 0.035s Metrics: {}
I20260812 06:19:23.057466 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:23.082185 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.025s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6452,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.082681 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling UndoDeltaBlockGCOp(aac2313b28e7462bbb788ad7249e01eb): 447 bytes on disk
I20260812 06:19:23.083101 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: UndoDeltaBlockGCOp(aac2313b28e7462bbb788ad7249e01eb) 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:19:23.083647 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=2.188937
I20260812 06:19:23.095104 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4459,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.096148 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:23.327042 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.231s	user 0.150s	sys 0.079s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":720,"lbm_read_time_us":14838,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38133,"lbm_writes_lt_1ms":743,"mutex_wait_us":391,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":15360,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:19:23.328075 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb): perf score=18.063937
I20260812 06:19:23.387395 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: FlushDeltaMemStoresOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.059s	user 0.031s	sys 0.023s Metrics: {"bytes_written":20512313,"delete_count":0,"lbm_write_time_us":25061,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:23.387884 16679 maintenance_manager.cc:419] P 45591522918945d5a6c3df3eca6ddf71: Scheduling MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb): perf score=1.000000
I20260812 06:19:23.398727 16103 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.703s	user 1.827s	sys 0.104s
I20260812 06:19:23.468214 16103 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.069s	user 0.001s	sys 0.000s
I20260812 06:19:23.468834 16103 tablet_server.cc:179] TabletServer@127.15.185.193:0 shutting down...
I20260812 06:19:23.534576 16589 maintenance_manager.cc:643] P 45591522918945d5a6c3df3eca6ddf71: MajorDeltaCompactionOp(aac2313b28e7462bbb788ad7249e01eb) complete. Timing: real 0.147s	user 0.096s	sys 0.050s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774569,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":637,"lbm_read_time_us":10636,"lbm_reads_lt_1ms":559,"lbm_write_time_us":25879,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2500}
I20260812 06:19:23.535181 16103 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:23.535466 16103 tablet_replica.cc:333] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71: stopping tablet replica
I20260812 06:19:23.535624 16103 raft_consensus.cc:2243] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:23.535796 16103 raft_consensus.cc:2272] T aac2313b28e7462bbb788ad7249e01eb P 45591522918945d5a6c3df3eca6ddf71 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:23.541177 16103 tablet_server.cc:196] TabletServer@127.15.185.193:0 shutdown complete.
I20260812 06:19:23.580361 16103 master.cc:562] Master@127.15.185.254:34309 shutting down...
I20260812 06:19:23.584204 16103 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:23.584401 16103 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:23.584491 16103 tablet_replica.cc:333] T 00000000000000000000000000000000 P d77e343fb1aa47c29bdd6d8b7fd21016: stopping tablet replica
I20260812 06:19:23.596936 16103 master.cc:584] Master@127.15.185.254:34309 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5215 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10618 ms total)

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