[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:00.313997  8079 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.7.227.254:45707
I20260812 06:20:00.315157  8079 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:00.315757  8079 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:00.322381  8085 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:00.322393  8084 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:00.322664  8079 server_base.cc:1061] running on GCE node
W20260812 06:20:00.322679  8087 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:00.323349  8079 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:00.323479  8079 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:00.323525  8079 hybrid_clock.cc:648] HybridClock initialized: now 1786515600323522 us; error 0 us; skew 500 ppm
I20260812 06:20:00.325472  8079 webserver.cc:533] Webserver started at http://127.7.227.254:38207/ using document root <none> and password file <none>
I20260812 06:20:00.326076  8079 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:00.326175  8079 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:00.326442  8079 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:00.328241  8079 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/master-0-root/instance:
uuid: "745149628cbb4f288606d9e1c3d3fda5"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-2w3w"
I20260812 06:20:00.331925  8079 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:20:00.334023  8093 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.335120  8079 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:20:00.335256  8079 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/master-0-root
uuid: "745149628cbb4f288606d9e1c3d3fda5"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-2w3w"
I20260812 06:20:00.335369  8079 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:00.348177  8079 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:00.348810  8079 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:00.348997  8079 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:00.356973  8079 rpc_server.cc:307] RPC server started. Bound to: 127.7.227.254:45707
I20260812 06:20:00.357023  8152 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.227.254:45707 every 8 connection(s)
I20260812 06:20:00.359390  8153 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:00.365305  8153 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5: Bootstrap starting.
I20260812 06:20:00.367823  8153 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:00.368739  8153 log.cc:826] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:00.370586  8153 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5: No bootstrap required, opened a new log
I20260812 06:20:00.373559  8153 raft_consensus.cc:359] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "745149628cbb4f288606d9e1c3d3fda5" member_type: VOTER }
I20260812 06:20:00.373744  8153 raft_consensus.cc:385] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:00.373795  8153 raft_consensus.cc:740] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 745149628cbb4f288606d9e1c3d3fda5, State: Initialized, Role: FOLLOWER
I20260812 06:20:00.374362  8153 consensus_queue.cc:260] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [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: "745149628cbb4f288606d9e1c3d3fda5" member_type: VOTER }
I20260812 06:20:00.374498  8153 raft_consensus.cc:399] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:00.374562  8153 raft_consensus.cc:493] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:00.374656  8153 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:00.375551  8153 raft_consensus.cc:515] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "745149628cbb4f288606d9e1c3d3fda5" member_type: VOTER }
I20260812 06:20:00.375998  8153 leader_election.cc:304] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [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: 745149628cbb4f288606d9e1c3d3fda5; no voters: 
I20260812 06:20:00.376298  8153 leader_election.cc:290] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:00.376523  8156 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:00.376837  8156 raft_consensus.cc:697] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [term 1 LEADER]: Becoming Leader. State: Replica: 745149628cbb4f288606d9e1c3d3fda5, State: Running, Role: LEADER
I20260812 06:20:00.377411  8153 sys_catalog.cc:565] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:00.377377  8156 consensus_queue.cc:237] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [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: "745149628cbb4f288606d9e1c3d3fda5" member_type: VOTER }
I20260812 06:20:00.379772  8158 sys_catalog.cc:455] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 745149628cbb4f288606d9e1c3d3fda5. Latest consensus state: current_term: 1 leader_uuid: "745149628cbb4f288606d9e1c3d3fda5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "745149628cbb4f288606d9e1c3d3fda5" member_type: VOTER } }
I20260812 06:20:00.380019  8158 sys_catalog.cc:458] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:00.380081  8079 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:00.379772  8157 sys_catalog.cc:455] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "745149628cbb4f288606d9e1c3d3fda5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "745149628cbb4f288606d9e1c3d3fda5" member_type: VOTER } }
I20260812 06:20:00.380259  8157 sys_catalog.cc:458] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:00.380897  8174 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:00.383316  8174 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:00.388969  8174 catalog_manager.cc:1383] Generated new cluster ID: 4a62d85d36f2489da575f9e24d76c7ed
I20260812 06:20:00.389082  8174 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:00.402590  8174 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:00.403618  8174 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:00.413475  8174 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5: Generated new TSK 0
I20260812 06:20:00.414207  8174 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:00.445031  8079 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:00.448046  8182 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:00.448319  8079 server_base.cc:1061] running on GCE node
W20260812 06:20:00.448068  8180 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:00.448089  8179 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:00.448685  8079 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:00.448745  8079 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:00.448762  8079 hybrid_clock.cc:648] HybridClock initialized: now 1786515600448762 us; error 0 us; skew 500 ppm
I20260812 06:20:00.449749  8079 webserver.cc:533] Webserver started at http://127.7.227.193:42483/ using document root <none> and password file <none>
I20260812 06:20:00.449949  8079 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:00.450028  8079 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:00.450143  8079 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:00.450570  8079 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/instance:
uuid: "a52d36285d7c430ba8e23da7dbf5b0fb"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-2w3w"
I20260812 06:20:00.452260  8079 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:00.453342  8187 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.453603  8079 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:00.453666  8079 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root
uuid: "a52d36285d7c430ba8e23da7dbf5b0fb"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-2w3w"
I20260812 06:20:00.453763  8079 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:00.467236  8079 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:00.467746  8079 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:00.468310  8079 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:00.469251  8079 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:00.469305  8079 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.469376  8079 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:00.469424  8079 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.476794  8079 rpc_server.cc:307] RPC server started. Bound to: 127.7.227.193:34201
I20260812 06:20:00.476823  8258 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.227.193:34201 every 8 connection(s)
I20260812 06:20:00.487684  8260 heartbeater.cc:344] Connected to a master server at 127.7.227.254:45707
I20260812 06:20:00.487951  8260 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:00.488452  8260 heartbeater.cc:507] Master 127.7.227.254:45707 requested a full tablet report, sending...
I20260812 06:20:00.490221  8109 ts_manager.cc:194] Registered new tserver with Master: a52d36285d7c430ba8e23da7dbf5b0fb (127.7.227.193:34201)
I20260812 06:20:00.491091  8079 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013624088s
I20260812 06:20:00.491816  8109 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:38902
I20260812 06:20:00.500968  8109 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:38912:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:00.515422  8219 tablet_service.cc:1511] Processing CreateTablet for tablet d61063f266b347e2849c3ffafdc559f8 (DEFAULT_TABLE table=heavy-update-compaction-test [id=3436f415bdaf4f0db00342e01fcfc6a7]), partition=
I20260812 06:20:00.515913  8219 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d61063f266b347e2849c3ffafdc559f8. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:00.518069  8273 tablet_bootstrap.cc:492] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Bootstrap starting.
I20260812 06:20:00.519236  8273 tablet_bootstrap.cc:654] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:00.520596  8273 tablet_bootstrap.cc:492] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: No bootstrap required, opened a new log
I20260812 06:20:00.520748  8273 ts_tablet_manager.cc:1403] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:00.521577  8273 raft_consensus.cc:359] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a52d36285d7c430ba8e23da7dbf5b0fb" member_type: VOTER last_known_addr { host: "127.7.227.193" port: 34201 } }
I20260812 06:20:00.521709  8273 raft_consensus.cc:385] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:00.521759  8273 raft_consensus.cc:740] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a52d36285d7c430ba8e23da7dbf5b0fb, State: Initialized, Role: FOLLOWER
I20260812 06:20:00.521908  8273 consensus_queue.cc:260] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb [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: "a52d36285d7c430ba8e23da7dbf5b0fb" member_type: VOTER last_known_addr { host: "127.7.227.193" port: 34201 } }
I20260812 06:20:00.522032  8273 raft_consensus.cc:399] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:00.522083  8273 raft_consensus.cc:493] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:00.522136  8273 raft_consensus.cc:3060] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:00.523180  8273 raft_consensus.cc:515] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a52d36285d7c430ba8e23da7dbf5b0fb" member_type: VOTER last_known_addr { host: "127.7.227.193" port: 34201 } }
I20260812 06:20:00.523355  8273 leader_election.cc:304] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb [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: a52d36285d7c430ba8e23da7dbf5b0fb; no voters: 
I20260812 06:20:00.523588  8273 leader_election.cc:290] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:00.523733  8275 raft_consensus.cc:2804] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:00.523983  8273 ts_tablet_manager.cc:1434] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:20:00.524019  8275 raft_consensus.cc:697] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb [term 1 LEADER]: Becoming Leader. State: Replica: a52d36285d7c430ba8e23da7dbf5b0fb, State: Running, Role: LEADER
I20260812 06:20:00.524225  8260 heartbeater.cc:499] Master 127.7.227.254:45707 was elected leader, sending a full tablet report...
I20260812 06:20:00.524217  8275 consensus_queue.cc:237] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb [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: "a52d36285d7c430ba8e23da7dbf5b0fb" member_type: VOTER last_known_addr { host: "127.7.227.193" port: 34201 } }
I20260812 06:20:00.527281  8109 catalog_manager.cc:5719] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb reported cstate change: term changed from 0 to 1, leader changed from <none> to a52d36285d7c430ba8e23da7dbf5b0fb (127.7.227.193). New cstate: current_term: 1 leader_uuid: "a52d36285d7c430ba8e23da7dbf5b0fb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a52d36285d7c430ba8e23da7dbf5b0fb" member_type: VOTER last_known_addr { host: "127.7.227.193" port: 34201 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:00.597886  8079 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.062s	user 0.022s	sys 0.006s
I20260812 06:20:00.727941  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushMRSOp(d61063f266b347e2849c3ffafdc559f8): perf score=15.086190
I20260812 06:20:00.899654  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushMRSOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.171s	user 0.137s	sys 0.031s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":265,"delete_count":0,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":889,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43743,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":159,"threads_started":1,"update_count":1450}
I20260812 06:20:00.901077  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling LogGCOp(d61063f266b347e2849c3ffafdc559f8): free 20743880 bytes of WAL
I20260812 06:20:00.901517  8192 log_reader.cc:385] T d61063f266b347e2849c3ffafdc559f8: removed 2 log segments from log reader
I20260812 06:20:00.901656  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000001 (ops 1-6)
I20260812 06:20:00.901767  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000002 (ops 7-11)
I20260812 06:20:00.908061  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: LogGCOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.007s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:20:00.908577  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:00.930038  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.021s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5934,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.930541  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:00.947176  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.016s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6621,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.947718  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:01.131278  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.183s	user 0.126s	sys 0.052s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364566,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":987,"lbm_read_time_us":13261,"lbm_reads_lt_1ms":563,"lbm_write_time_us":31720,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":355,"threads_started":5,"update_count":2450}
I20260812 06:20:01.132045  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=11.118625
I20260812 06:20:01.162621  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.030s	user 0.013s	sys 0.014s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":13569,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:01.163270  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling UndoDeltaBlockGCOp(d61063f266b347e2849c3ffafdc559f8): 12719216 bytes on disk
I20260812 06:20:01.164011  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: UndoDeltaBlockGCOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":121,"lbm_reads_lt_1ms":4}
I20260812 06:20:01.164727  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:01.181349  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.016s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4393,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.181852  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:01.318522  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.137s	user 0.108s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":536,"lbm_read_time_us":8247,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28593,"lbm_writes_lt_1ms":443,"mutex_wait_us":94,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:01.319355  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=10.126437
I20260812 06:20:01.360082  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.040s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15931,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:01.360574  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:01.372855  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4285,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.373639  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:01.508818  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.135s	user 0.115s	sys 0.019s 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":673,"lbm_read_time_us":10488,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25925,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:20:01.509450  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=10.126437
I20260812 06:20:01.557711  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.048s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17399,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:01.558346  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:01.569802  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4618,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.570261  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:01.731585  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.161s	user 0.090s	sys 0.070s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1082,"lbm_read_time_us":12600,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25147,"lbm_writes_lt_1ms":443,"mutex_wait_us":368,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:01.732120  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=10.126437
I20260812 06:20:01.783603  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.051s	user 0.030s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17519,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1500}
I20260812 06:20:01.784157  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:01.796345  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4458,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.796907  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:01.921692  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.125s	user 0.097s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":485,"lbm_read_time_us":9037,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23749,"lbm_writes_lt_1ms":443,"mutex_wait_us":106,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:20:01.922354  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=10.126437
I20260812 06:20:01.967458  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.045s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19591,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:01.968001  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:01.979635  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4190,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.980180  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:02.111908  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.132s	user 0.103s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":206,"lbm_read_time_us":10806,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24505,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2000}
I20260812 06:20:02.112560  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=10.126437
I20260812 06:20:02.165529  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.053s	user 0.030s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17399,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:02.166232  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:02.183723  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6540,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.184664  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushMRSOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:02.230168  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushMRSOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.045s	user 0.030s	sys 0.005s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":90,"dirs.run_cpu_time_us":273,"dirs.run_wall_time_us":1677,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1970,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:02.231263  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling LogGCOp(d61063f266b347e2849c3ffafdc559f8): free 108535451 bytes of WAL
I20260812 06:20:02.231540  8192 log_reader.cc:385] T d61063f266b347e2849c3ffafdc559f8: removed 11 log segments from log reader
I20260812 06:20:02.231590  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000003 (ops 12-16)
I20260812 06:20:02.231662  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000004 (ops 17-20)
I20260812 06:20:02.231715  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000005 (ops 21-25)
I20260812 06:20:02.231736  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000006 (ops 26-30)
I20260812 06:20:02.231755  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000007 (ops 31-35)
I20260812 06:20:02.231771  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000008 (ops 36-40)
I20260812 06:20:02.231787  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000009 (ops 41-45)
I20260812 06:20:02.231804  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000010 (ops 46-50)
I20260812 06:20:02.231863  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000011 (ops 51-54)
I20260812 06:20:02.231904  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000012 (ops 55-59)
I20260812 06:20:02.231988  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000013 (ops 60-64)
I20260812 06:20:02.258450  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: LogGCOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:20:02.259091  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling UndoDeltaBlockGCOp(d61063f266b347e2849c3ffafdc559f8): 446 bytes on disk
I20260812 06:20:02.259632  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: UndoDeltaBlockGCOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:20:02.260391  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=3.181125
I20260812 06:20:02.284446  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.024s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7453,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:02.285036  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:02.296016  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4213,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.296720  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:02.507681  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.211s	user 0.158s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1275,"lbm_read_time_us":13637,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35798,"lbm_writes_lt_1ms":643,"mutex_wait_us":30,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":112384,"thread_start_us":114,"threads_started":1,"update_count":3000}
I20260812 06:20:02.508385  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=14.095187
I20260812 06:20:02.576840  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.068s	user 0.033s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26787,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.577402  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:02.590469  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4691,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.591271  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:02.777546  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.186s	user 0.136s	sys 0.044s 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":1019,"lbm_read_time_us":13369,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32925,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":100224,"update_count":2500}
I20260812 06:20:02.778262  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=14.095187
I20260812 06:20:02.846127  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.068s	user 0.026s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24701,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.846691  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:02.860852  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.861335  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:03.055150  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.194s	user 0.138s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":267,"lbm_read_time_us":14706,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31709,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:20:03.055860  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=14.095187
I20260812 06:20:03.123930  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.068s	user 0.037s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24451,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.124544  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:03.136749  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4827,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.137315  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:03.322909  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.185s	user 0.125s	sys 0.060s 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":283,"lbm_read_time_us":14344,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33263,"lbm_writes_lt_1ms":543,"mutex_wait_us":78,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2500}
I20260812 06:20:03.324069  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=11.118625
I20260812 06:20:03.364107  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.040s	user 0.024s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17163,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:03.364859  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:03.381973  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.017s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4849,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.382560  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:03.561504  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.179s	user 0.107s	sys 0.057s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":10886,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26002,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":2000}
I20260812 06:20:03.562178  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=11.118625
I20260812 06:20:03.601800  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.039s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17302,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:03.602442  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:03.619211  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.017s	user 0.012s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5701,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":450}
I20260812 06:20:03.619843  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:03.764750  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.145s	user 0.112s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1124,"lbm_read_time_us":11045,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27379,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":2000}
I20260812 06:20:03.767055  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=10.126437
I20260812 06:20:03.811681  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.044s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19388,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:03.812249  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:03.823997  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.824798  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushMRSOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:03.855875  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushMRSOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.031s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":1708,"drs_written":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1658,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:03.856676  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling LogGCOp(d61063f266b347e2849c3ffafdc559f8): free 124257192 bytes of WAL
I20260812 06:20:03.856966  8192 log_reader.cc:385] T d61063f266b347e2849c3ffafdc559f8: removed 12 log segments from log reader
I20260812 06:20:03.857028  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000014 (ops 65-69)
I20260812 06:20:03.857067  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000015 (ops 70-74)
I20260812 06:20:03.857223  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000016 (ops 75-79)
I20260812 06:20:03.857263  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000017 (ops 80-84)
I20260812 06:20:03.857290  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000018 (ops 85-89)
I20260812 06:20:03.857318  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000019 (ops 90-94)
I20260812 06:20:03.857352  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000020 (ops 95-98)
I20260812 06:20:03.857383  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000021 (ops 99-103)
I20260812 06:20:03.857411  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000022 (ops 104-108)
I20260812 06:20:03.857441  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000023 (ops 109-113)
I20260812 06:20:03.857467  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000024 (ops 114-118)
I20260812 06:20:03.857496  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000025 (ops 119-123)
I20260812 06:20:03.893081  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: LogGCOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.036s	user 0.000s	sys 0.034s Metrics: {}
I20260812 06:20:03.893488  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling UndoDeltaBlockGCOp(d61063f266b347e2849c3ffafdc559f8): 462 bytes on disk
I20260812 06:20:03.893949  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: UndoDeltaBlockGCOp(d61063f266b347e2849c3ffafdc559f8) 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:20:03.894459  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:03.917979  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.023s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4657,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.918568  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:03.930552  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4554,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.931277  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:04.130535  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.199s	user 0.156s	sys 0.042s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":460,"lbm_read_time_us":16219,"lbm_reads_lt_1ms":674,"lbm_write_time_us":39807,"lbm_writes_lt_1ms":643,"mutex_wait_us":50,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14976,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:20:04.132984  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=14.095187
I20260812 06:20:04.209074  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.076s	user 0.031s	sys 0.026s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":41686,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.209915  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:04.237304  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.027s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6027,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.237828  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:04.249213  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4254,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.249936  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:04.427697  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.178s	user 0.138s	sys 0.036s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877221,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":435,"lbm_read_time_us":12565,"lbm_reads_lt_1ms":673,"lbm_write_time_us":40133,"lbm_writes_lt_1ms":643,"mutex_wait_us":71,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":3000}
I20260812 06:20:04.428277  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=14.095187
I20260812 06:20:04.484409  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.056s	user 0.040s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22875,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.484905  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:04.498159  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4619,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.498756  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:04.665773  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.167s	user 0.115s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":690,"lbm_read_time_us":11224,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33130,"lbm_writes_lt_1ms":543,"mutex_wait_us":343,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:20:04.666599  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=14.095187
I20260812 06:20:04.721830  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.055s	user 0.038s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23787,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.722364  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:04.734352  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4536,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.735241  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:04.929240  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.194s	user 0.114s	sys 0.077s 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":161,"lbm_read_time_us":12615,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33682,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:04.930022  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=14.095187
I20260812 06:20:04.981017  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.051s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23380,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.981564  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:05.144408  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.163s	user 0.110s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":624,"lbm_read_time_us":12874,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27949,"lbm_writes_lt_1ms":443,"mutex_wait_us":323,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.145550  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=11.118625
I20260812 06:20:05.197502  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.052s	user 0.016s	sys 0.032s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":22642,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:05.198163  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:05.211431  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4788,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.212035  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:05.226308  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5544,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:05.227077  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:05.435809  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.208s	user 0.129s	sys 0.065s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1126,"lbm_read_time_us":11809,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33519,"lbm_writes_lt_1ms":543,"mutex_wait_us":309,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:05.436468  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=14.095187
I20260812 06:20:05.492698  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.056s	user 0.026s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26444,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.493258  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=2.188937
I20260812 06:20:05.505975  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.012s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5074,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.506438  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushMRSOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:05.539386  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushMRSOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1397,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1871,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:05.540095  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling LogGCOp(d61063f266b347e2849c3ffafdc559f8): free 133024623 bytes of WAL
I20260812 06:20:05.540339  8192 log_reader.cc:385] T d61063f266b347e2849c3ffafdc559f8: removed 13 log segments from log reader
I20260812 06:20:05.540385  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000026 (ops 124-128)
I20260812 06:20:05.540416  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000027 (ops 129-133)
I20260812 06:20:05.540432  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000028 (ops 134-139)
I20260812 06:20:05.540493  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000029 (ops 140-144)
I20260812 06:20:05.540542  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000030 (ops 145-148)
I20260812 06:20:05.540561  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000031 (ops 149-153)
I20260812 06:20:05.540613  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000032 (ops 154-158)
I20260812 06:20:05.540657  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000033 (ops 159-163)
I20260812 06:20:05.540699  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000034 (ops 164-168)
I20260812 06:20:05.540742  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000035 (ops 169-173)
I20260812 06:20:05.540773  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000036 (ops 174-178)
I20260812 06:20:05.540830  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000037 (ops 179-182)
I20260812 06:20:05.540870  8192 log.cc:1079] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d61063f266b347e2849c3ffafdc559f8/wal-000000038 (ops 183-187)
I20260812 06:20:05.576604  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: LogGCOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.036s	user 0.000s	sys 0.035s Metrics: {}
I20260812 06:20:05.577600  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling UndoDeltaBlockGCOp(d61063f266b347e2849c3ffafdc559f8): 492 bytes on disk
I20260812 06:20:05.578403  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: UndoDeltaBlockGCOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4}
I20260812 06:20:05.579062  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=4.173312
I20260812 06:20:05.594532  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":5784657,"delete_count":0,"lbm_write_time_us":6646,"lbm_writes_lt_1ms":144,"reinsert_count":0,"update_count":705}
I20260812 06:20:05.595108  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.196750
I20260812 06:20:05.602504  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.007s	user 0.001s	sys 0.005s Metrics: {"bytes_written":2420629,"delete_count":0,"lbm_write_time_us":2633,"lbm_writes_lt_1ms":62,"reinsert_count":0,"update_count":295}
I20260812 06:20:05.603055  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8): perf score=1.000000
I20260812 06:20:05.852139  8079 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.254s	user 1.891s	sys 0.152s
I20260812 06:20:05.865222  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: MajorDeltaCompactionOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.262s	user 0.170s	sys 0.081s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979713,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":299,"lbm_read_time_us":18485,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41723,"lbm_writes_lt_1ms":743,"mutex_wait_us":32,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":20736,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:20:05.865902  8262 maintenance_manager.cc:419] P a52d36285d7c430ba8e23da7dbf5b0fb: Scheduling FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8): perf score=18.063937
I20260812 06:20:05.923848  8079 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.071s	user 0.006s	sys 0.000s
I20260812 06:20:05.924496  8079 tablet_server.cc:179] TabletServer@127.7.227.193:0 shutting down...
I20260812 06:20:05.935300  8192 maintenance_manager.cc:643] P a52d36285d7c430ba8e23da7dbf5b0fb: FlushDeltaMemStoresOp(d61063f266b347e2849c3ffafdc559f8) complete. Timing: real 0.069s	user 0.042s	sys 0.027s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":31551,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:05.935962  8079 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:05.936373  8079 tablet_replica.cc:333] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb: stopping tablet replica
I20260812 06:20:05.936604  8079 raft_consensus.cc:2243] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:05.936878  8079 raft_consensus.cc:2272] T d61063f266b347e2849c3ffafdc559f8 P a52d36285d7c430ba8e23da7dbf5b0fb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:05.941453  8079 tablet_server.cc:196] TabletServer@127.7.227.193:0 shutdown complete.
I20260812 06:20:05.945984  8079 master.cc:562] Master@127.7.227.254:45707 shutting down...
I20260812 06:20:05.950080  8079 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:05.950238  8079 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:05.950309  8079 tablet_replica.cc:333] T 00000000000000000000000000000000 P 745149628cbb4f288606d9e1c3d3fda5: stopping tablet replica
I20260812 06:20:05.962745  8079 master.cc:584] Master@127.7.227.254:45707 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5748 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:06.061407  8079 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.7.227.254:46833
I20260812 06:20:06.061756  8079 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:20:06.064428  8079 server_base.cc:1061] running on GCE node
W20260812 06:20:06.064349  8294 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:06.064409  8298 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:06.064349  8296 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:06.064754  8079 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:06.064810  8079 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:06.064826  8079 hybrid_clock.cc:648] HybridClock initialized: now 1786515606064826 us; error 0 us; skew 500 ppm
I20260812 06:20:06.065676  8079 webserver.cc:533] Webserver started at http://127.7.227.254:42443/ using document root <none> and password file <none>
I20260812 06:20:06.065811  8079 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:06.065855  8079 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:06.065908  8079 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:06.066251  8079 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/master-0-root/instance:
uuid: "1900042973404eb2982fa6af896e7f69"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-2w3w"
I20260812 06:20:06.067865  8079 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:06.068823  8303 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.069156  8079 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:06.069257  8079 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/master-0-root
uuid: "1900042973404eb2982fa6af896e7f69"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-2w3w"
I20260812 06:20:06.069351  8079 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:06.094899  8079 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:06.095383  8079 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:06.099825  8079 rpc_server.cc:307] RPC server started. Bound to: 127.7.227.254:46833
I20260812 06:20:06.102809  8361 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.227.254:46833 every 8 connection(s)
I20260812 06:20:06.106940  8363 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:06.116312  8363 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69: Bootstrap starting.
I20260812 06:20:06.117157  8363 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:06.118290  8363 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69: No bootstrap required, opened a new log
I20260812 06:20:06.118700  8363 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1900042973404eb2982fa6af896e7f69" member_type: VOTER }
I20260812 06:20:06.118794  8363 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:06.118818  8363 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1900042973404eb2982fa6af896e7f69, State: Initialized, Role: FOLLOWER
I20260812 06:20:06.118983  8363 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [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: "1900042973404eb2982fa6af896e7f69" member_type: VOTER }
I20260812 06:20:06.119107  8363 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:06.119134  8363 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:06.119166  8363 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:06.119900  8363 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1900042973404eb2982fa6af896e7f69" member_type: VOTER }
I20260812 06:20:06.120024  8363 leader_election.cc:304] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [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: 1900042973404eb2982fa6af896e7f69; no voters: 
I20260812 06:20:06.120201  8363 leader_election.cc:290] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:06.120395  8367 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:06.120604  8367 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [term 1 LEADER]: Becoming Leader. State: Replica: 1900042973404eb2982fa6af896e7f69, State: Running, Role: LEADER
I20260812 06:20:06.120744  8363 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:06.120822  8367 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [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: "1900042973404eb2982fa6af896e7f69" member_type: VOTER }
I20260812 06:20:06.121325  8368 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1900042973404eb2982fa6af896e7f69" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1900042973404eb2982fa6af896e7f69" member_type: VOTER } }
I20260812 06:20:06.121344  8369 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1900042973404eb2982fa6af896e7f69. Latest consensus state: current_term: 1 leader_uuid: "1900042973404eb2982fa6af896e7f69" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1900042973404eb2982fa6af896e7f69" member_type: VOTER } }
I20260812 06:20:06.121454  8369 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:06.121711  8368 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:06.121757  8373 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:06.123118  8373 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:06.123324  8079 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:06.125190  8373 catalog_manager.cc:1383] Generated new cluster ID: ff5c774815f1426a8a8c8aaa37025dba
I20260812 06:20:06.125253  8373 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:06.149431  8373 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:06.150015  8373 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:06.156690  8373 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69: Generated new TSK 0
I20260812 06:20:06.156915  8373 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:06.188249  8079 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:06.190711  8389 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:06.190697  8387 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:06.190817  8079 server_base.cc:1061] running on GCE node
W20260812 06:20:06.190729  8386 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:06.191250  8079 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:06.191303  8079 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:06.191320  8079 hybrid_clock.cc:648] HybridClock initialized: now 1786515606191320 us; error 0 us; skew 500 ppm
I20260812 06:20:06.192245  8079 webserver.cc:533] Webserver started at http://127.7.227.193:34673/ using document root <none> and password file <none>
I20260812 06:20:06.192441  8079 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:06.192515  8079 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:06.192602  8079 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:06.193010  8079 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/instance:
uuid: "34287792154f436bb81e3d8e192efd59"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-2w3w"
I20260812 06:20:06.194541  8079 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:06.195604  8396 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.195855  8079 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:06.195947  8079 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root
uuid: "34287792154f436bb81e3d8e192efd59"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-2w3w"
I20260812 06:20:06.196040  8079 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:06.201315  8079 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:06.201758  8079 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:06.202085  8079 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:06.202569  8079 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:06.202631  8079 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.202695  8079 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:06.202729  8079 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.207129  8079 rpc_server.cc:307] RPC server started. Bound to: 127.7.227.193:40807
I20260812 06:20:06.207892  8466 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.227.193:40807 every 8 connection(s)
I20260812 06:20:06.216907  8467 heartbeater.cc:344] Connected to a master server at 127.7.227.254:46833
I20260812 06:20:06.217056  8467 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:06.217374  8467 heartbeater.cc:507] Master 127.7.227.254:46833 requested a full tablet report, sending...
I20260812 06:20:06.218160  8323 ts_manager.cc:194] Registered new tserver with Master: 34287792154f436bb81e3d8e192efd59 (127.7.227.193:40807)
I20260812 06:20:06.218317  8079 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.0102816s
I20260812 06:20:06.219065  8323 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57866
I20260812 06:20:06.226467  8323 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57880:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:06.236186  8426 tablet_service.cc:1511] Processing CreateTablet for tablet d54db8e9a1844886854074d968756781 (DEFAULT_TABLE table=heavy-update-compaction-test [id=f0fca8c36611483bb00e68a9a4fe3af8]), partition=
I20260812 06:20:06.236501  8426 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d54db8e9a1844886854074d968756781. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:06.238622  8481 tablet_bootstrap.cc:492] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Bootstrap starting.
I20260812 06:20:06.239557  8481 tablet_bootstrap.cc:654] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:06.240546  8481 tablet_bootstrap.cc:492] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: No bootstrap required, opened a new log
I20260812 06:20:06.240622  8481 ts_tablet_manager.cc:1403] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:06.241158  8481 raft_consensus.cc:359] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "34287792154f436bb81e3d8e192efd59" member_type: VOTER last_known_addr { host: "127.7.227.193" port: 40807 } }
I20260812 06:20:06.241285  8481 raft_consensus.cc:385] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:06.241365  8481 raft_consensus.cc:740] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 34287792154f436bb81e3d8e192efd59, State: Initialized, Role: FOLLOWER
I20260812 06:20:06.241532  8481 consensus_queue.cc:260] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59 [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: "34287792154f436bb81e3d8e192efd59" member_type: VOTER last_known_addr { host: "127.7.227.193" port: 40807 } }
I20260812 06:20:06.241637  8481 raft_consensus.cc:399] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:06.241683  8481 raft_consensus.cc:493] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:06.241735  8481 raft_consensus.cc:3060] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:06.242486  8481 raft_consensus.cc:515] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "34287792154f436bb81e3d8e192efd59" member_type: VOTER last_known_addr { host: "127.7.227.193" port: 40807 } }
I20260812 06:20:06.242643  8481 leader_election.cc:304] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59 [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: 34287792154f436bb81e3d8e192efd59; no voters: 
I20260812 06:20:06.242866  8481 leader_election.cc:290] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:06.243045  8483 raft_consensus.cc:2804] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:06.243283  8481 ts_tablet_manager.cc:1434] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:06.243323  8483 raft_consensus.cc:697] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59 [term 1 LEADER]: Becoming Leader. State: Replica: 34287792154f436bb81e3d8e192efd59, State: Running, Role: LEADER
I20260812 06:20:06.243289  8467 heartbeater.cc:499] Master 127.7.227.254:46833 was elected leader, sending a full tablet report...
I20260812 06:20:06.243556  8483 consensus_queue.cc:237] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59 [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: "34287792154f436bb81e3d8e192efd59" member_type: VOTER last_known_addr { host: "127.7.227.193" port: 40807 } }
I20260812 06:20:06.244870  8323 catalog_manager.cc:5719] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59 reported cstate change: term changed from 0 to 1, leader changed from <none> to 34287792154f436bb81e3d8e192efd59 (127.7.227.193). New cstate: current_term: 1 leader_uuid: "34287792154f436bb81e3d8e192efd59" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "34287792154f436bb81e3d8e192efd59" member_type: VOTER last_known_addr { host: "127.7.227.193" port: 40807 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:06.310263  8079 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.013s	sys 0.011s
I20260812 06:20:06.458542  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushMRSOp(d54db8e9a1844886854074d968756781): perf score=19.054940
I20260812 06:20:06.624657  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushMRSOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.166s	user 0.114s	sys 0.044s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":120,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":1018,"drs_written":1,"lbm_read_time_us":158,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43978,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":14208,"update_count":1500}
I20260812 06:20:06.625399  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling LogGCOp(d54db8e9a1844886854074d968756781): free 20743831 bytes of WAL
I20260812 06:20:06.625634  8401 log_reader.cc:385] T d54db8e9a1844886854074d968756781: removed 2 log segments from log reader
I20260812 06:20:06.625681  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000001 (ops 1-6)
I20260812 06:20:06.625735  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000002 (ops 7-11)
I20260812 06:20:06.630776  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: LogGCOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:06.632673  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:06.648070  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.015s	user 0.008s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5828,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.648649  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling UndoDeltaBlockGCOp(d54db8e9a1844886854074d968756781): 16411393 bytes on disk
I20260812 06:20:06.649276  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: UndoDeltaBlockGCOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":104,"lbm_reads_lt_1ms":4}
I20260812 06:20:06.649762  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:06.814847  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.165s	user 0.109s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":582,"lbm_read_time_us":13019,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26875,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":370,"threads_started":5,"update_count":2000}
I20260812 06:20:06.815722  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=14.095187
I20260812 06:20:06.878396  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.062s	user 0.026s	sys 0.029s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25587,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.878867  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:06.890617  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4366,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.891142  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:07.092187  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.201s	user 0.143s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1149,"lbm_read_time_us":15031,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32369,"lbm_writes_lt_1ms":543,"mutex_wait_us":377,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18688,"update_count":2500}
I20260812 06:20:07.092821  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=14.095187
I20260812 06:20:07.157401  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.064s	user 0.026s	sys 0.033s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21687,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:07.157980  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:07.169189  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.169703  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:07.357728  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.188s	user 0.132s	sys 0.056s 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":200,"lbm_read_time_us":13942,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29815,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:20:07.358546  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=14.095187
I20260812 06:20:07.426141  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.067s	user 0.026s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19699,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:07.426949  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:07.443552  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.016s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6397,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.443997  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:07.639590  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.195s	user 0.118s	sys 0.071s 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":94,"lbm_read_time_us":14776,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31188,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":2500}
I20260812 06:20:07.640538  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=11.118625
I20260812 06:20:07.678176  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.037s	user 0.013s	sys 0.022s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16264,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:07.678884  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:07.693259  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4919,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:07.693805  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:07.830814  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.137s	user 0.098s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":235,"lbm_read_time_us":10781,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26236,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:20:07.831591  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=10.126437
I20260812 06:20:07.863410  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.032s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14077,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.863917  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:07.876938  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4831,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.877624  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:08.009330  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.131s	user 0.107s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":372,"lbm_read_time_us":9076,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26208,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:20:08.010015  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=10.126437
I20260812 06:20:08.055321  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.045s	user 0.010s	sys 0.027s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16707,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:08.055891  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:08.067619  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4125,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.068239  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushMRSOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:08.102698  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushMRSOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1701,"drs_written":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1794,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:08.103489  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling LogGCOp(d54db8e9a1844886854074d968756781): free 124710343 bytes of WAL
I20260812 06:20:08.103734  8401 log_reader.cc:385] T d54db8e9a1844886854074d968756781: removed 12 log segments from log reader
I20260812 06:20:08.103782  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000003 (ops 12-16)
I20260812 06:20:08.103843  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000004 (ops 17-21)
I20260812 06:20:08.103888  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000005 (ops 22-26)
I20260812 06:20:08.103943  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000006 (ops 27-31)
I20260812 06:20:08.103981  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000007 (ops 32-36)
I20260812 06:20:08.104024  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000008 (ops 37-41)
I20260812 06:20:08.104065  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000009 (ops 42-46)
I20260812 06:20:08.104105  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000010 (ops 47-51)
I20260812 06:20:08.104144  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000011 (ops 52-56)
I20260812 06:20:08.104183  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000012 (ops 57-61)
I20260812 06:20:08.104223  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000013 (ops 62-66)
I20260812 06:20:08.104261  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000014 (ops 67-71)
I20260812 06:20:08.133512  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: LogGCOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:08.133934  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling UndoDeltaBlockGCOp(d54db8e9a1844886854074d968756781): 483 bytes on disk
I20260812 06:20:08.134459  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: UndoDeltaBlockGCOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:20:08.135022  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=3.181125
I20260812 06:20:08.148694  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5123,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:08.149274  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:08.164783  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5691,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:08.165565  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:08.359005  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.193s	user 0.141s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":724,"lbm_read_time_us":12758,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40024,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4480,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:20:08.359694  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=14.095187
I20260812 06:20:08.415398  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.055s	user 0.048s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25194,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.415966  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:08.429904  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5376,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":500}
I20260812 06:20:08.430487  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:08.622752  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.192s	user 0.136s	sys 0.048s 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":283,"lbm_read_time_us":10819,"lbm_reads_lt_1ms":564,"lbm_write_time_us":36526,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":37504,"update_count":2500}
I20260812 06:20:08.623783  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=14.095187
I20260812 06:20:08.671319  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.047s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21070,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.672092  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:08.832854  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.161s	user 0.128s	sys 0.031s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":646,"lbm_read_time_us":10449,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27323,"lbm_writes_lt_1ms":443,"mutex_wait_us":328,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2000}
I20260812 06:20:08.833665  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=11.118625
I20260812 06:20:08.880430  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.047s	user 0.021s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20864,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:08.880985  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:08.895705  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.015s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4293,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:08.896445  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:09.050180  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.154s	user 0.126s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":116,"lbm_read_time_us":9721,"lbm_reads_lt_1ms":464,"lbm_write_time_us":31828,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.050987  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=10.126437
I20260812 06:20:09.104138  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.053s	user 0.032s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22668,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:09.104848  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:09.124331  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.019s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6445,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.124897  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:09.347700  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.223s	user 0.195s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":839,"lbm_read_time_us":15706,"lbm_reads_lt_1ms":464,"lbm_write_time_us":36814,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.348471  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=18.063937
I20260812 06:20:09.436604  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.088s	user 0.058s	sys 0.023s Metrics: {"bytes_written":20512312,"delete_count":0,"lbm_write_time_us":36394,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:09.437327  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=6.157687
I20260812 06:20:09.480321  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.043s	user 0.017s	sys 0.016s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":14161,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:09.481030  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:09.500617  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.019s	user 0.018s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7114,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.501268  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:09.729871  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.228s	user 0.156s	sys 0.072s Metrics: {"cfile_cache_miss":833,"cfile_cache_miss_bytes":37082043,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":395,"lbm_read_time_us":17705,"lbm_reads_lt_1ms":873,"lbm_write_time_us":46751,"lbm_writes_lt_1ms":843,"mutex_wait_us":23,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":4000}
I20260812 06:20:09.730768  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=18.063937
I20260812 06:20:09.799355  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.068s	user 0.048s	sys 0.019s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":30282,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:09.800120  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:09.827235  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.027s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5784,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.827760  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:09.838994  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4392,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.839807  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushMRSOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:09.878652  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushMRSOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.039s	user 0.033s	sys 0.004s Metrics: {"bytes_written":1398560,"cfile_init":1,"dirs.queue_time_us":109,"dirs.run_cpu_time_us":275,"dirs.run_wall_time_us":1891,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2118,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":34}
I20260812 06:20:09.879504  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling LogGCOp(d54db8e9a1844886854074d968756781): free 141338478 bytes of WAL
I20260812 06:20:09.879786  8401 log_reader.cc:385] T d54db8e9a1844886854074d968756781: removed 14 log segments from log reader
I20260812 06:20:09.879842  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000015 (ops 72-76)
I20260812 06:20:09.879899  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000016 (ops 77-81)
I20260812 06:20:09.879953  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000017 (ops 82-86)
I20260812 06:20:09.879997  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000018 (ops 87-90)
I20260812 06:20:09.880039  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000019 (ops 91-95)
I20260812 06:20:09.880072  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000020 (ops 96-100)
I20260812 06:20:09.880116  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000021 (ops 101-104)
I20260812 06:20:09.880158  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000022 (ops 105-109)
I20260812 06:20:09.880200  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000023 (ops 110-114)
I20260812 06:20:09.880246  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000024 (ops 115-119)
I20260812 06:20:09.880288  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000025 (ops 120-124)
I20260812 06:20:09.880329  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000026 (ops 125-129)
I20260812 06:20:09.880371  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000027 (ops 130-134)
I20260812 06:20:09.880412  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000028 (ops 135-139)
I20260812 06:20:09.919045  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: LogGCOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.039s	user 0.000s	sys 0.039s Metrics: {}
I20260812 06:20:09.919869  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=6.157687
I20260812 06:20:09.946904  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.027s	user 0.020s	sys 0.004s Metrics: {"bytes_written":7425620,"delete_count":0,"lbm_write_time_us":11332,"lbm_writes_lt_1ms":184,"reinsert_count":0,"update_count":905}
I20260812 06:20:09.947660  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling UndoDeltaBlockGCOp(d54db8e9a1844886854074d968756781): 516 bytes on disk
I20260812 06:20:09.948455  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: UndoDeltaBlockGCOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":117,"lbm_reads_lt_1ms":4}
I20260812 06:20:09.949057  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:10.205693  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.256s	user 0.204s	sys 0.052s Metrics: {"cfile_cache_miss":915,"cfile_cache_miss_bytes":40405123,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":612,"lbm_read_time_us":19574,"lbm_reads_lt_1ms":951,"lbm_write_time_us":53400,"lbm_writes_lt_1ms":924,"mutex_wait_us":176,"peak_mem_usage":109961755,"reinsert_count":0,"spinlock_wait_cycles":1592320,"thread_start_us":90,"threads_started":1,"update_count":4405}
I20260812 06:20:10.211323  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=19.056125
I20260812 06:20:10.305595  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.090s	user 0.048s	sys 0.037s Metrics: {"bytes_written":21291779,"delete_count":0,"lbm_write_time_us":39701,"lbm_writes_lt_1ms":522,"reinsert_count":0,"update_count":2595}
I20260812 06:20:10.306353  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=3.181125
I20260812 06:20:10.319864  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5477,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:10.320441  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:10.333038  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4315,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:10.333693  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:10.578339  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.244s	user 0.146s	sys 0.097s Metrics: {"cfile_cache_miss":752,"cfile_cache_miss_bytes":33759084,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":250,"lbm_read_time_us":20217,"lbm_reads_lt_1ms":792,"lbm_write_time_us":43289,"lbm_writes_lt_1ms":762,"mutex_wait_us":69,"peak_mem_usage":89789093,"reinsert_count":0,"spinlock_wait_cycles":38016,"update_count":3595}
I20260812 06:20:10.581703  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=18.063937
I20260812 06:20:10.648806  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.067s	user 0.038s	sys 0.023s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":28730,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:10.649427  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:10.665875  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.016s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6565,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.666599  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:10.849731  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.183s	user 0.155s	sys 0.027s 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":754,"lbm_read_time_us":14725,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37195,"lbm_writes_lt_1ms":643,"mutex_wait_us":410,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":3000}
I20260812 06:20:10.850484  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=14.095187
I20260812 06:20:10.904844  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.054s	user 0.040s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24411,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.905467  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:10.921628  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6211,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.922238  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:11.110612  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.188s	user 0.134s	sys 0.044s 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":350,"lbm_read_time_us":14242,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33845,"lbm_writes_lt_1ms":543,"mutex_wait_us":80,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:20:11.111348  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=14.095187
I20260812 06:20:11.167004  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.055s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":25280,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.167734  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:11.333158  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.165s	user 0.113s	sys 0.050s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1066,"lbm_read_time_us":11976,"lbm_reads_lt_1ms":467,"lbm_write_time_us":29269,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:20:11.334012  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=11.118625
I20260812 06:20:11.372856  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.039s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16743,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:11.373708  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:11.391333  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5516,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:11.391876  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushMRSOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:11.432822  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushMRSOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.041s	user 0.026s	sys 0.002s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":289,"dirs.run_wall_time_us":2151,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1703,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:11.433609  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=3.181125
I20260812 06:20:11.455953  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.022s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4870,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:11.456540  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling LogGCOp(d54db8e9a1844886854074d968756781): free 121006705 bytes of WAL
I20260812 06:20:11.456845  8401 log_reader.cc:385] T d54db8e9a1844886854074d968756781: removed 12 log segments from log reader
I20260812 06:20:11.456897  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000029 (ops 140-144)
I20260812 06:20:11.456929  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000030 (ops 145-149)
I20260812 06:20:11.456972  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000031 (ops 150-154)
I20260812 06:20:11.457017  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000032 (ops 155-159)
I20260812 06:20:11.457065  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000033 (ops 160-164)
I20260812 06:20:11.457111  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000034 (ops 165-169)
I20260812 06:20:11.457137  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000035 (ops 170-174)
I20260812 06:20:11.457182  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000036 (ops 175-178)
I20260812 06:20:11.457224  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000037 (ops 179-183)
I20260812 06:20:11.457264  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000038 (ops 184-188)
I20260812 06:20:11.457299  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000039 (ops 189-193)
I20260812 06:20:11.457345  8401 log.cc:1079] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: Deleting log segment in path: /tmp/dist-test-taskhbUiee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515600302629-8079-0/minicluster-data/ts-0-root/wals/d54db8e9a1844886854074d968756781/wal-000000040 (ops 194-198)
I20260812 06:20:11.484647  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: LogGCOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:11.485155  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781): perf score=2.188937
I20260812 06:20:11.501825  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: FlushDeltaMemStoresOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.016s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5135,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:11.502529  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling UndoDeltaBlockGCOp(d54db8e9a1844886854074d968756781): 463 bytes on disk
I20260812 06:20:11.503158  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: UndoDeltaBlockGCOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:20:11.503695  8468 maintenance_manager.cc:419] P 34287792154f436bb81e3d8e192efd59: Scheduling MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781): perf score=1.000000
I20260812 06:20:11.513852  8079 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.203s	user 1.894s	sys 0.158s
I20260812 06:20:11.601493  8079 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.087s	user 0.001s	sys 0.000s
I20260812 06:20:11.602077  8079 tablet_server.cc:179] TabletServer@127.7.227.193:0 shutting down...
I20260812 06:20:11.686704  8401 maintenance_manager.cc:643] P 34287792154f436bb81e3d8e192efd59: MajorDeltaCompactionOp(d54db8e9a1844886854074d968756781) complete. Timing: real 0.183s	user 0.123s	sys 0.056s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877317,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":506,"lbm_read_time_us":13469,"lbm_reads_lt_1ms":662,"lbm_write_time_us":32159,"lbm_writes_lt_1ms":643,"mutex_wait_us":110,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":44416,"thread_start_us":95,"threads_started":1,"update_count":3000}
I20260812 06:20:11.687448  8079 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:11.687690  8079 tablet_replica.cc:333] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59: stopping tablet replica
I20260812 06:20:11.687855  8079 raft_consensus.cc:2243] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:11.688046  8079 raft_consensus.cc:2272] T d54db8e9a1844886854074d968756781 P 34287792154f436bb81e3d8e192efd59 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:11.704146  8079 tablet_server.cc:196] TabletServer@127.7.227.193:0 shutdown complete.
I20260812 06:20:11.733899  8079 master.cc:562] Master@127.7.227.254:46833 shutting down...
I20260812 06:20:11.738139  8079 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:11.738339  8079 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:11.738394  8079 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1900042973404eb2982fa6af896e7f69: stopping tablet replica
I20260812 06:20:11.751350  8079 master.cc:584] Master@127.7.227.254:46833 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5784 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11533 ms total)

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