[==========] 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:18:04.697602 13353 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.10.126:42155
I20260812 06:18:04.698922 13353 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:18:04.699644 13353 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:04.707705 13365 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:18:04.707738 13360 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:18:04.708106 13361 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:18:04.708107 13353 server_base.cc:1061] running on GCE node
I20260812 06:18:04.709336 13353 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:04.709565 13353 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:18:04.709637 13353 hybrid_clock.cc:648] HybridClock initialized: now 1786515484709635 us; error 0 us; skew 500 ppm
I20260812 06:18:04.712113 13353 webserver.cc:533] Webserver started at http://127.13.10.126:38813/ using document root <none> and password file <none>
I20260812 06:18:04.712816 13353 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:04.712891 13353 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:04.713176 13353 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:04.715230 13353 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/master-0-root/instance:
uuid: "1c54364793954d6d809de577b2238a5d"
format_stamp: "Formatted at 2026-08-12 06:18:04 on dist-test-slave-7z32"
I20260812 06:18:04.720357 13353 fs_manager.cc:696] Time spent creating directory manager: real 0.005s	user 0.003s	sys 0.001s
I20260812 06:18:04.723755 13371 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:18:04.725695 13353 fs_manager.cc:730] Time spent opening block manager: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:18:04.726271 13353 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/master-0-root
uuid: "1c54364793954d6d809de577b2238a5d"
format_stamp: "Formatted at 2026-08-12 06:18:04 on dist-test-slave-7z32"
I20260812 06:18:04.726457 13353 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-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:18:04.739112 13353 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:04.739887 13353 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:18:04.740099 13353 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:04.749953 13353 rpc_server.cc:307] RPC server started. Bound to: 127.13.10.126:42155
I20260812 06:18:04.749960 13459 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.10.126:42155 every 8 connection(s)
I20260812 06:18:04.753414 13460 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:18:04.761459 13460 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d: Bootstrap starting.
I20260812 06:18:04.765177 13460 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:04.766647 13460 log.cc:826] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:04.769706 13460 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d: No bootstrap required, opened a new log
I20260812 06:18:04.773717 13460 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c54364793954d6d809de577b2238a5d" member_type: VOTER }
I20260812 06:18:04.774106 13460 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:04.774195 13460 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1c54364793954d6d809de577b2238a5d, State: Initialized, Role: FOLLOWER
I20260812 06:18:04.775359 13460 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [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: "1c54364793954d6d809de577b2238a5d" member_type: VOTER }
I20260812 06:18:04.775610 13460 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:04.775672 13460 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:04.775802 13460 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:04.776911 13460 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c54364793954d6d809de577b2238a5d" member_type: VOTER }
I20260812 06:18:04.777534 13460 leader_election.cc:304] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [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: 1c54364793954d6d809de577b2238a5d; no voters: 
I20260812 06:18:04.777980 13460 leader_election.cc:290] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:04.778339 13463 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:04.778869 13463 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [term 1 LEADER]: Becoming Leader. State: Replica: 1c54364793954d6d809de577b2238a5d, State: Running, Role: LEADER
I20260812 06:18:04.779456 13463 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [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: "1c54364793954d6d809de577b2238a5d" member_type: VOTER }
I20260812 06:18:04.779695 13460 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:04.782264 13464 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1c54364793954d6d809de577b2238a5d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c54364793954d6d809de577b2238a5d" member_type: VOTER } }
I20260812 06:18:04.782275 13465 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1c54364793954d6d809de577b2238a5d. Latest consensus state: current_term: 1 leader_uuid: "1c54364793954d6d809de577b2238a5d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c54364793954d6d809de577b2238a5d" member_type: VOTER } }
I20260812 06:18:04.782461 13464 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:04.782476 13465 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:04.782866 13353 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:18:04.785487 13484 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:04.785581 13484 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:04.785681 13481 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:04.786686 13481 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:04.793591 13481 catalog_manager.cc:1383] Generated new cluster ID: 6e11a99fc9844091b32c47419bf0acbe
I20260812 06:18:04.793712 13481 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:04.837874 13481 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:04.839398 13481 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:04.856269 13481 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d: Generated new TSK 0
I20260812 06:18:04.857216 13481 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:04.912953 13353 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:04.916935 13495 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:18:04.917423 13353 server_base.cc:1061] running on GCE node
W20260812 06:18:04.917169 13492 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:18:04.917006 13491 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:18:04.917815 13353 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:04.917912 13353 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:18:04.917935 13353 hybrid_clock.cc:648] HybridClock initialized: now 1786515484917935 us; error 0 us; skew 500 ppm
I20260812 06:18:04.919282 13353 webserver.cc:533] Webserver started at http://127.13.10.65:37179/ using document root <none> and password file <none>
I20260812 06:18:04.919494 13353 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:04.919577 13353 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:04.919688 13353 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:04.920416 13353 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/instance:
uuid: "668169c52a284939b96434836a3646a8"
format_stamp: "Formatted at 2026-08-12 06:18:04 on dist-test-slave-7z32"
I20260812 06:18:04.922857 13353 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:04.924966 13503 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:18:04.925499 13353 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:04.925606 13353 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root
uuid: "668169c52a284939b96434836a3646a8"
format_stamp: "Formatted at 2026-08-12 06:18:04 on dist-test-slave-7z32"
I20260812 06:18:04.925719 13353 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-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:18:04.947335 13353 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:04.948123 13353 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:04.948822 13353 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:04.949889 13353 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:04.949975 13353 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:04.950065 13353 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:04.950111 13353 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:04.959399 13353 rpc_server.cc:307] RPC server started. Bound to: 127.13.10.65:43197
I20260812 06:18:04.959625 13619 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.10.65:43197 every 8 connection(s)
I20260812 06:18:04.973438 13620 heartbeater.cc:344] Connected to a master server at 127.13.10.126:42155
I20260812 06:18:04.973799 13620 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:04.974474 13620 heartbeater.cc:507] Master 127.13.10.126:42155 requested a full tablet report, sending...
I20260812 06:18:04.976666 13392 ts_manager.cc:194] Registered new tserver with Master: 668169c52a284939b96434836a3646a8 (127.13.10.65:43197)
I20260812 06:18:04.976934 13353 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016626847s
I20260812 06:18:04.978178 13392 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55708
I20260812 06:18:04.990257 13392 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55712:
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:18:05.009301 13553 tablet_service.cc:1511] Processing CreateTablet for tablet 6c7ba98233e6454fb847565483c00926 (DEFAULT_TABLE table=heavy-update-compaction-test [id=82457d36a2e749a2a55a76c2ca480852]), partition=
I20260812 06:18:05.010025 13553 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6c7ba98233e6454fb847565483c00926. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:05.014125 13635 tablet_bootstrap.cc:492] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Bootstrap starting.
I20260812 06:18:05.015225 13635 tablet_bootstrap.cc:654] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:05.016880 13635 tablet_bootstrap.cc:492] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: No bootstrap required, opened a new log
I20260812 06:18:05.017042 13635 ts_tablet_manager.cc:1403] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:05.017554 13635 raft_consensus.cc:359] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "668169c52a284939b96434836a3646a8" member_type: VOTER last_known_addr { host: "127.13.10.65" port: 43197 } }
I20260812 06:18:05.017758 13635 raft_consensus.cc:385] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:05.017810 13635 raft_consensus.cc:740] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 668169c52a284939b96434836a3646a8, State: Initialized, Role: FOLLOWER
I20260812 06:18:05.017980 13635 consensus_queue.cc:260] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8 [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: "668169c52a284939b96434836a3646a8" member_type: VOTER last_known_addr { host: "127.13.10.65" port: 43197 } }
I20260812 06:18:05.018096 13635 raft_consensus.cc:399] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:05.018150 13635 raft_consensus.cc:493] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:05.018203 13635 raft_consensus.cc:3060] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:05.019196 13635 raft_consensus.cc:515] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "668169c52a284939b96434836a3646a8" member_type: VOTER last_known_addr { host: "127.13.10.65" port: 43197 } }
I20260812 06:18:05.019384 13635 leader_election.cc:304] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8 [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: 668169c52a284939b96434836a3646a8; no voters: 
I20260812 06:18:05.019652 13635 leader_election.cc:290] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:05.020117 13640 raft_consensus.cc:2804] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:05.020665 13640 raft_consensus.cc:697] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8 [term 1 LEADER]: Becoming Leader. State: Replica: 668169c52a284939b96434836a3646a8, State: Running, Role: LEADER
I20260812 06:18:05.020721 13635 ts_tablet_manager.cc:1434] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Time spent starting tablet: real 0.004s	user 0.001s	sys 0.003s
I20260812 06:18:05.021081 13620 heartbeater.cc:499] Master 127.13.10.126:42155 was elected leader, sending a full tablet report...
I20260812 06:18:05.021016 13640 consensus_queue.cc:237] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8 [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: "668169c52a284939b96434836a3646a8" member_type: VOTER last_known_addr { host: "127.13.10.65" port: 43197 } }
I20260812 06:18:05.025709 13392 catalog_manager.cc:5719] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8 reported cstate change: term changed from 0 to 1, leader changed from <none> to 668169c52a284939b96434836a3646a8 (127.13.10.65). New cstate: current_term: 1 leader_uuid: "668169c52a284939b96434836a3646a8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "668169c52a284939b96434836a3646a8" member_type: VOTER last_known_addr { host: "127.13.10.65" port: 43197 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:05.113133 13353 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.072s	user 0.023s	sys 0.011s
I20260812 06:18:05.210963 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushMRSOp(6c7ba98233e6454fb847565483c00926): perf score=10.125253
I20260812 06:18:05.378005 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushMRSOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.166s	user 0.130s	sys 0.033s Metrics: {"bytes_written":8738396,"cfile_init":1,"compiler_manager_pool.queue_time_us":379,"delete_count":0,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":299,"dirs.run_wall_time_us":1536,"drs_written":1,"lbm_read_time_us":120,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34544,"lbm_writes_lt_1ms":470,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"spinlock_wait_cycles":143616,"thread_start_us":223,"threads_started":1,"update_count":1065}
I20260812 06:18:05.379776 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling LogGCOp(6c7ba98233e6454fb847565483c00926): free 11976772 bytes of WAL
I20260812 06:18:05.380230 13511 log_reader.cc:385] T 6c7ba98233e6454fb847565483c00926: removed 1 log segments from log reader
I20260812 06:18:05.380311 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000001 (ops 1-6)
I20260812 06:18:05.385664 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: LogGCOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:05.386562 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling UndoDeltaBlockGCOp(6c7ba98233e6454fb847565483c00926): 8206539 bytes on disk
I20260812 06:18:05.387948 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: UndoDeltaBlockGCOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":118,"lbm_reads_lt_1ms":4}
I20260812 06:18:05.388995 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:05.405426 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3569334,"delete_count":0,"lbm_write_time_us":6085,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:18:05.406157 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:05.557350 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.151s	user 0.119s	sys 0.028s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487928,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":665,"lbm_read_time_us":10052,"lbm_reads_lt_1ms":360,"lbm_write_time_us":26827,"lbm_writes_lt_1ms":343,"mutex_wait_us":27,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":486656,"thread_start_us":416,"threads_started":5,"update_count":1500}
I20260812 06:18:05.558126 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=10.126437
I20260812 06:18:05.631493 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.073s	user 0.043s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":24405,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:05.632331 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:05.651052 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.018s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6876,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.651981 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:05.819437 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.167s	user 0.131s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":870,"lbm_read_time_us":12009,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32096,"lbm_writes_lt_1ms":443,"mutex_wait_us":219,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2000}
I20260812 06:18:05.820191 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=10.126437
I20260812 06:18:05.889524 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.069s	user 0.041s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":21236,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:05.890286 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:05.902078 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4503,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.903098 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:06.068979 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.166s	user 0.117s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590346,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":186,"lbm_read_time_us":13793,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25923,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:18:06.069679 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=6.157687
I20260812 06:18:06.110257 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.040s	user 0.014s	sys 0.015s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":13657,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:06.111093 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:06.126003 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.015s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5376,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:06.126787 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:06.254606 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.127s	user 0.090s	sys 0.037s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487935,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":523,"lbm_read_time_us":9959,"lbm_reads_lt_1ms":372,"lbm_write_time_us":22826,"lbm_writes_lt_1ms":343,"mutex_wait_us":310,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":1500}
I20260812 06:18:06.255344 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=6.157687
I20260812 06:18:06.307934 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.052s	user 0.025s	sys 0.016s Metrics: {"bytes_written":8205080,"delete_count":0,"lbm_write_time_us":19625,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":201,"reinsert_count":0,"update_count":1000}
I20260812 06:18:06.308723 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:06.323555 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4954,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:06.324230 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:06.487946 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.163s	user 0.104s	sys 0.052s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487937,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1009,"lbm_read_time_us":11925,"lbm_reads_lt_1ms":372,"lbm_write_time_us":29936,"lbm_writes_lt_1ms":343,"mutex_wait_us":80,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":1500}
I20260812 06:18:06.488842 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=10.126437
I20260812 06:18:06.545425 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.056s	user 0.022s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21030,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:06.546344 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:06.559458 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:06.560235 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:06.719885 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.159s	user 0.117s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1384,"lbm_read_time_us":11534,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27811,"lbm_writes_lt_1ms":443,"mutex_wait_us":76,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:06.720732 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=10.126437
I20260812 06:18:06.776044 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.055s	user 0.048s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22325,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:06.776904 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:06.793293 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5733,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:06.794308 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:06.967880 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.173s	user 0.135s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":705,"lbm_read_time_us":13284,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32922,"lbm_writes_lt_1ms":443,"mutex_wait_us":316,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2000}
I20260812 06:18:06.968894 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=10.126437
I20260812 06:18:07.019644 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.050s	user 0.031s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18526,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:07.020828 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:07.038394 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6542,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:07.039176 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushMRSOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:07.075870 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushMRSOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.036s	user 0.035s	sys 0.001s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":110,"dirs.run_cpu_time_us":328,"dirs.run_wall_time_us":1407,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1873,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29,"spinlock_wait_cycles":1280}
I20260812 06:18:07.077029 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling LogGCOp(6c7ba98233e6454fb847565483c00926): free 121006445 bytes of WAL
I20260812 06:18:07.077335 13511 log_reader.cc:385] T 6c7ba98233e6454fb847565483c00926: removed 12 log segments from log reader
I20260812 06:18:07.077385 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000002 (ops 7-11)
I20260812 06:18:07.077423 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000003 (ops 12-16)
I20260812 06:18:07.077471 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000004 (ops 17-20)
I20260812 06:18:07.077517 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000005 (ops 21-25)
I20260812 06:18:07.077548 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000006 (ops 26-30)
I20260812 06:18:07.077605 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000007 (ops 31-35)
I20260812 06:18:07.077641 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000008 (ops 36-40)
I20260812 06:18:07.077697 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000009 (ops 41-45)
I20260812 06:18:07.077728 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000010 (ops 46-50)
I20260812 06:18:07.077847 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000011 (ops 51-55)
I20260812 06:18:07.077905 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000012 (ops 56-60)
I20260812 06:18:07.077950 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000013 (ops 61-65)
I20260812 06:18:07.112267 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: LogGCOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.035s	user 0.000s	sys 0.034s Metrics: {}
I20260812 06:18:07.113022 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=6.157687
I20260812 06:18:07.153865 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.041s	user 0.027s	sys 0.000s Metrics: {"bytes_written":7958933,"delete_count":0,"lbm_write_time_us":12418,"lbm_writes_lt_1ms":197,"reinsert_count":0,"update_count":970}
I20260812 06:18:07.154805 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling UndoDeltaBlockGCOp(6c7ba98233e6454fb847565483c00926): 462 bytes on disk
I20260812 06:18:07.155615 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: UndoDeltaBlockGCOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:18:07.156383 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:07.351835 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.195s	user 0.141s	sys 0.047s Metrics: {"cfile_cache_miss":627,"cfile_cache_miss_bytes":28549146,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2204,"lbm_read_time_us":14258,"lbm_reads_lt_1ms":659,"lbm_write_time_us":37483,"lbm_writes_lt_1ms":637,"mutex_wait_us":1988,"peak_mem_usage":74255878,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":271,"threads_started":1,"update_count":2970}
I20260812 06:18:07.352794 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=11.118625
I20260812 06:18:07.405318 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.052s	user 0.035s	sys 0.013s Metrics: {"bytes_written":12963886,"delete_count":0,"lbm_write_time_us":22962,"lbm_writes_lt_1ms":319,"reinsert_count":0,"update_count":1580}
I20260812 06:18:07.406031 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:07.423627 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5357,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:07.424301 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:07.443127 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.019s	user 0.011s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6670,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:07.443934 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:07.633637 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.189s	user 0.138s	sys 0.051s Metrics: {"cfile_cache_miss":539,"cfile_cache_miss_bytes":24939020,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":260,"lbm_read_time_us":13946,"lbm_reads_lt_1ms":579,"lbm_write_time_us":39342,"lbm_writes_lt_1ms":549,"mutex_wait_us":64,"peak_mem_usage":63362110,"reinsert_count":0,"spinlock_wait_cycles":18816,"update_count":2530}
I20260812 06:18:07.634599 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=14.095187
I20260812 06:18:07.704190 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.069s	user 0.037s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27976,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:07.704890 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:07.722775 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.018s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6657,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:07.723704 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:07.923362 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.199s	user 0.156s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":712,"lbm_read_time_us":12926,"lbm_reads_lt_1ms":564,"lbm_write_time_us":38123,"lbm_writes_lt_1ms":543,"mutex_wait_us":89,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":44160,"update_count":2500}
I20260812 06:18:07.924635 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=14.095187
I20260812 06:18:08.000744 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.076s	user 0.049s	sys 0.012s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":29509,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:08.001480 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:08.019419 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.018s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7073,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.020196 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:08.229708 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.209s	user 0.134s	sys 0.075s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692762,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1627,"lbm_read_time_us":18165,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35628,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:08.230638 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=14.095187
I20260812 06:18:08.305371 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.074s	user 0.031s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24152,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:08.306114 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:08.319830 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.014s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5594,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.320376 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:08.526688 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.206s	user 0.128s	sys 0.077s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1362,"lbm_read_time_us":15931,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34441,"lbm_writes_lt_1ms":543,"mutex_wait_us":604,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:18:08.527937 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=10.126437
I20260812 06:18:08.586881 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.058s	user 0.026s	sys 0.026s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":25600,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:08.587877 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:08.615339 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.027s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6815,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.615906 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:08.796679 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.181s	user 0.112s	sys 0.064s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":411,"lbm_read_time_us":11761,"lbm_reads_lt_1ms":464,"lbm_write_time_us":30443,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:08.797713 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=10.126437
I20260812 06:18:08.847703 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.049s	user 0.025s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20385,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:08.848348 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:08.859730 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4271,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.860317 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushMRSOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:08.904811 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushMRSOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.044s	user 0.027s	sys 0.002s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":387,"dirs.run_wall_time_us":1901,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1894,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:08.905719 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling LogGCOp(6c7ba98233e6454fb847565483c00926): free 124257256 bytes of WAL
I20260812 06:18:08.906167 13511 log_reader.cc:385] T 6c7ba98233e6454fb847565483c00926: removed 12 log segments from log reader
I20260812 06:18:08.906231 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000014 (ops 66-70)
I20260812 06:18:08.906267 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000015 (ops 71-75)
I20260812 06:18:08.906327 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000016 (ops 76-80)
I20260812 06:18:08.906381 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000017 (ops 81-85)
I20260812 06:18:08.906420 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000018 (ops 86-90)
I20260812 06:18:08.906471 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000019 (ops 91-95)
I20260812 06:18:08.906502 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000020 (ops 96-100)
I20260812 06:18:08.906569 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000021 (ops 101-104)
I20260812 06:18:08.906620 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000022 (ops 105-109)
I20260812 06:18:08.906665 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000023 (ops 110-114)
I20260812 06:18:08.906708 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000024 (ops 115-119)
I20260812 06:18:08.906754 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000025 (ops 120-124)
I20260812 06:18:08.936805 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: LogGCOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.031s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:18:08.937595 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:08.964834 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.027s	user 0.012s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8530,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.965715 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:08.982309 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5860,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.982957 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:09.205651 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.222s	user 0.143s	sys 0.068s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795410,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1776,"lbm_read_time_us":13649,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38412,"lbm_writes_lt_1ms":643,"mutex_wait_us":65,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":99,"threads_started":1,"update_count":3000}
I20260812 06:18:09.206765 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=11.118625
I20260812 06:18:09.244397 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.037s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16599,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:09.245069 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling UndoDeltaBlockGCOp(6c7ba98233e6454fb847565483c00926): 473 bytes on disk
I20260812 06:18:09.245769 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: UndoDeltaBlockGCOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":124,"lbm_reads_lt_1ms":4}
I20260812 06:18:09.246395 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:09.264037 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6039,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:09.264603 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:09.416071 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.151s	user 0.128s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590338,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":448,"lbm_read_time_us":8957,"lbm_reads_lt_1ms":468,"lbm_write_time_us":28323,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2000}
I20260812 06:18:09.416779 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=10.126437
I20260812 06:18:09.469807 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.053s	user 0.020s	sys 0.022s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20634,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:09.470525 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:09.483238 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.012s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4575,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.483786 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:09.624126 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.140s	user 0.104s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590349,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":261,"lbm_read_time_us":9760,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26155,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:09.624963 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=7.149875
I20260812 06:18:09.661720 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.036s	user 0.015s	sys 0.011s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":13166,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:09.662267 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:09.672585 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3789,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:09.673082 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:09.795720 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.122s	user 0.091s	sys 0.031s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487926,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":302,"lbm_read_time_us":9891,"lbm_reads_lt_1ms":372,"lbm_write_time_us":22048,"lbm_writes_lt_1ms":343,"mutex_wait_us":27,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":1500}
I20260812 06:18:09.796494 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=6.157687
I20260812 06:18:09.830602 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.034s	user 0.017s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11502,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:09.831669 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:09.921815 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.090s	user 0.069s	sys 0.021s Metrics: {"cfile_cache_miss":231,"cfile_cache_miss_bytes":12385404,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":465,"lbm_read_time_us":5193,"lbm_reads_lt_1ms":263,"lbm_write_time_us":16110,"lbm_writes_lt_1ms":243,"mutex_wait_us":129,"peak_mem_usage":25836184,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":1000}
I20260812 06:18:09.922614 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=6.157687
I20260812 06:18:09.953534 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.031s	user 0.018s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12170,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:09.954110 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:10.069432 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.115s	user 0.094s	sys 0.020s Metrics: {"cfile_cache_miss":231,"cfile_cache_miss_bytes":12385404,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":2016,"lbm_read_time_us":8367,"lbm_reads_lt_1ms":267,"lbm_write_time_us":21043,"lbm_writes_lt_1ms":243,"mutex_wait_us":560,"peak_mem_usage":25836184,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":1000}
I20260812 06:18:10.070531 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=6.157687
I20260812 06:18:10.117480 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.047s	user 0.020s	sys 0.015s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":16416,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":202,"reinsert_count":0,"update_count":1000}
I20260812 06:18:10.118330 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:10.139779 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.021s	user 0.013s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7807,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.140636 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:10.282060 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.141s	user 0.112s	sys 0.024s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487935,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1176,"lbm_read_time_us":10742,"lbm_reads_lt_1ms":372,"lbm_write_time_us":22376,"lbm_writes_lt_1ms":343,"mutex_wait_us":431,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":1500}
I20260812 06:18:10.283182 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=7.149875
I20260812 06:18:10.309168 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.026s	user 0.007s	sys 0.017s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11407,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:10.309836 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:10.321837 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4631,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:10.322436 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:10.454445 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.132s	user 0.086s	sys 0.043s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487926,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":771,"lbm_read_time_us":11496,"lbm_reads_lt_1ms":372,"lbm_write_time_us":23734,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"mutex_wait_us":67,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":1500}
I20260812 06:18:10.455229 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=6.157687
I20260812 06:18:10.495090 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.040s	user 0.011s	sys 0.014s Metrics: {"bytes_written":8205080,"delete_count":0,"lbm_write_time_us":10127,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:10.496176 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:10.512485 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.016s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6135,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.513166 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:10.653312 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.140s	user 0.118s	sys 0.015s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487937,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":671,"lbm_read_time_us":12001,"lbm_reads_lt_1ms":372,"lbm_write_time_us":25957,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"mutex_wait_us":3,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.654021 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=6.157687
I20260812 06:18:10.684965 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.031s	user 0.026s	sys 0.000s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":11724,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:10.685726 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushMRSOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:10.716681 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushMRSOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.031s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":103,"dirs.run_cpu_time_us":349,"dirs.run_wall_time_us":2224,"drs_written":1,"lbm_read_time_us":103,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1785,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:10.717622 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling LogGCOp(6c7ba98233e6454fb847565483c00926): free 112239534 bytes of WAL
I20260812 06:18:10.717875 13511 log_reader.cc:385] T 6c7ba98233e6454fb847565483c00926: removed 11 log segments from log reader
I20260812 06:18:10.717927 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000026 (ops 125-129)
I20260812 06:18:10.717959 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000027 (ops 130-134)
I20260812 06:18:10.718027 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000028 (ops 135-139)
I20260812 06:18:10.718072 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000029 (ops 140-144)
I20260812 06:18:10.718116 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000030 (ops 145-149)
I20260812 06:18:10.718158 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000031 (ops 150-154)
I20260812 06:18:10.718200 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000032 (ops 155-159)
I20260812 06:18:10.718242 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000033 (ops 160-164)
I20260812 06:18:10.718272 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000034 (ops 165-169)
I20260812 06:18:10.718322 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000035 (ops 170-174)
I20260812 06:18:10.718375 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000036 (ops 175-178)
I20260812 06:18:10.747925 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: LogGCOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:10.748641 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling UndoDeltaBlockGCOp(6c7ba98233e6454fb847565483c00926): 463 bytes on disk
I20260812 06:18:10.749603 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: UndoDeltaBlockGCOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":149,"lbm_reads_lt_1ms":4}
I20260812 06:18:10.750566 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:10.775784 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.025s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5938,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.776729 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling LogGCOp(6c7ba98233e6454fb847565483c00926): free 8767140 bytes of WAL
I20260812 06:18:10.777207 13511 log_reader.cc:385] T 6c7ba98233e6454fb847565483c00926: removed 1 log segments from log reader
I20260812 06:18:10.777300 13511 log.cc:1079] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/6c7ba98233e6454fb847565483c00926/wal-000000037 (ops 179-183)
I20260812 06:18:10.779604 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: LogGCOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:10.780122 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:10.795763 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.015s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5135,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.796497 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:10.947628 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.151s	user 0.118s	sys 0.029s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20590465,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1259,"lbm_read_time_us":10796,"lbm_reads_lt_1ms":473,"lbm_write_time_us":28973,"lbm_writes_lt_1ms":443,"mutex_wait_us":141,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":98,"threads_started":1,"update_count":2000}
I20260812 06:18:10.948603 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=10.126437
I20260812 06:18:11.032938 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.084s	user 0.024s	sys 0.040s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18558,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.034197 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=1.196750
I20260812 06:18:11.050648 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.015s	user 0.006s	sys 0.005s Metrics: {"bytes_written":2584733,"delete_count":0,"lbm_write_time_us":3946,"lbm_writes_lt_1ms":66,"reinsert_count":0,"update_count":315}
I20260812 06:18:11.052187 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:11.062279 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.010s	user 0.007s	sys 0.000s Metrics: {"bytes_written":1518077,"delete_count":0,"lbm_write_time_us":2616,"lbm_writes_lt_1ms":40,"reinsert_count":0,"update_count":185}
I20260812 06:18:11.063282 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:11.309337 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.246s	user 0.167s	sys 0.076s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20590371,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":302,"lbm_read_time_us":32048,"lbm_reads_1-10_ms":5,"lbm_reads_lt_1ms":468,"lbm_write_time_us":35490,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:18:11.310420 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=11.118625
I20260812 06:18:11.358214 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.047s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":20071,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:11.359176 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:11.385561 13353 heavy-update-compaction-itest.cc:229] Time spent updating: real 6.272s	user 2.219s	sys 0.205s
I20260812 06:18:11.387790 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.028s	user 0.007s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6546,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:11.388831 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926): perf score=2.188937
I20260812 06:18:11.407347 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: FlushDeltaMemStoresOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.018s	user 0.006s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7143,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":500}
I20260812 06:18:11.408147 13621 maintenance_manager.cc:419] P 668169c52a284939b96434836a3646a8: Scheduling MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926): perf score=1.000000
I20260812 06:18:11.469728 13353 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.083s	user 0.001s	sys 0.002s
I20260812 06:18:11.470954 13353 tablet_server.cc:179] TabletServer@127.13.10.65:0 shutting down...
I20260812 06:18:11.553354 13511 maintenance_manager.cc:643] P 668169c52a284939b96434836a3646a8: MajorDeltaCompactionOp(6c7ba98233e6454fb847565483c00926) complete. Timing: real 0.145s	user 0.116s	sys 0.028s Metrics: {"cfile_cache_hit":292,"cfile_cache_hit_bytes":11898669,"cfile_cache_miss":241,"cfile_cache_miss_bytes":12794201,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":819,"lbm_read_time_us":7722,"lbm_reads_lt_1ms":273,"lbm_write_time_us":28494,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":150784,"update_count":2500}
I20260812 06:18:11.554392 13353 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:11.555115 13353 tablet_replica.cc:333] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8: stopping tablet replica
I20260812 06:18:11.555500 13353 raft_consensus.cc:2243] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:11.555853 13353 raft_consensus.cc:2272] T 6c7ba98233e6454fb847565483c00926 P 668169c52a284939b96434836a3646a8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:11.574409 13353 tablet_server.cc:196] TabletServer@127.13.10.65:0 shutdown complete.
I20260812 06:18:11.603116 13353 master.cc:562] Master@127.13.10.126:42155 shutting down...
I20260812 06:18:11.608637 13353 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:11.608927 13353 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:11.609212 13353 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1c54364793954d6d809de577b2238a5d: stopping tablet replica
I20260812 06:18:11.622961 13353 master.cc:584] Master@127.13.10.126:42155 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (7037 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:11.734067 13353 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.10.126:34927
I20260812 06:18:11.734458 13353 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:11.737264 13677 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:18:11.737382 13670 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:18:11.737699 13671 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:18:11.737736 13353 server_base.cc:1061] running on GCE node
I20260812 06:18:11.738170 13353 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:11.738255 13353 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:18:11.738276 13353 hybrid_clock.cc:648] HybridClock initialized: now 1786515491738276 us; error 0 us; skew 500 ppm
I20260812 06:18:11.740022 13353 webserver.cc:533] Webserver started at http://127.13.10.126:42901/ using document root <none> and password file <none>
I20260812 06:18:11.740334 13353 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:11.740414 13353 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:11.740605 13353 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:11.741207 13353 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/master-0-root/instance:
uuid: "a6dcca23c4b642abb07379e84212d762"
format_stamp: "Formatted at 2026-08-12 06:18:11 on dist-test-slave-7z32"
I20260812 06:18:11.743746 13353 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.002s
I20260812 06:18:11.745498 13683 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:18:11.746127 13353 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:11.746309 13353 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/master-0-root
uuid: "a6dcca23c4b642abb07379e84212d762"
format_stamp: "Formatted at 2026-08-12 06:18:11 on dist-test-slave-7z32"
I20260812 06:18:11.746438 13353 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-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:18:11.759137 13353 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:11.759755 13353 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:11.766227 13353 rpc_server.cc:307] RPC server started. Bound to: 127.13.10.126:34927
I20260812 06:18:11.769297 13775 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.10.126:34927 every 8 connection(s)
I20260812 06:18:11.773362 13778 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:18:11.786405 13778 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762: Bootstrap starting.
I20260812 06:18:11.788002 13778 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:11.791206 13778 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762: No bootstrap required, opened a new log
I20260812 06:18:11.791987 13778 raft_consensus.cc:359] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6dcca23c4b642abb07379e84212d762" member_type: VOTER }
I20260812 06:18:11.792204 13778 raft_consensus.cc:385] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:11.792249 13778 raft_consensus.cc:740] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a6dcca23c4b642abb07379e84212d762, State: Initialized, Role: FOLLOWER
I20260812 06:18:11.792448 13778 consensus_queue.cc:260] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [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: "a6dcca23c4b642abb07379e84212d762" member_type: VOTER }
I20260812 06:18:11.792560 13778 raft_consensus.cc:399] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:11.792588 13778 raft_consensus.cc:493] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:11.792622 13778 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:11.793773 13778 raft_consensus.cc:515] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6dcca23c4b642abb07379e84212d762" member_type: VOTER }
I20260812 06:18:11.793939 13778 leader_election.cc:304] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [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: a6dcca23c4b642abb07379e84212d762; no voters: 
I20260812 06:18:11.794227 13778 leader_election.cc:290] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:11.794397 13783 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:11.794616 13783 raft_consensus.cc:697] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [term 1 LEADER]: Becoming Leader. State: Replica: a6dcca23c4b642abb07379e84212d762, State: Running, Role: LEADER
I20260812 06:18:11.794790 13783 consensus_queue.cc:237] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [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: "a6dcca23c4b642abb07379e84212d762" member_type: VOTER }
I20260812 06:18:11.795045 13778 sys_catalog.cc:565] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:11.795639 13785 sys_catalog.cc:455] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [sys.catalog]: SysCatalogTable state changed. Reason: New leader a6dcca23c4b642abb07379e84212d762. Latest consensus state: current_term: 1 leader_uuid: "a6dcca23c4b642abb07379e84212d762" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6dcca23c4b642abb07379e84212d762" member_type: VOTER } }
I20260812 06:18:11.795782 13785 sys_catalog.cc:458] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:11.795588 13786 sys_catalog.cc:455] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a6dcca23c4b642abb07379e84212d762" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6dcca23c4b642abb07379e84212d762" member_type: VOTER } }
I20260812 06:18:11.795933 13786 sys_catalog.cc:458] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:11.796185 13791 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:11.797422 13791 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:11.797783 13353 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:11.800400 13791 catalog_manager.cc:1383] Generated new cluster ID: 0b9433ac8cbb4c838e4422521bc84be4
I20260812 06:18:11.800524 13791 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:11.818753 13791 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:11.820070 13791 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:11.833036 13791 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762: Generated new TSK 0
I20260812 06:18:11.833379 13791 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:11.863649 13353 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:11.866532 13814 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:18:11.866808 13353 server_base.cc:1061] running on GCE node
W20260812 06:18:11.866897 13809 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:18:11.867125 13806 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:18:11.867482 13353 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:11.867556 13353 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:18:11.867583 13353 hybrid_clock.cc:648] HybridClock initialized: now 1786515491867582 us; error 0 us; skew 500 ppm
I20260812 06:18:11.868758 13353 webserver.cc:533] Webserver started at http://127.13.10.65:45321/ using document root <none> and password file <none>
I20260812 06:18:11.868999 13353 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:11.869098 13353 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:11.869197 13353 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:11.869761 13353 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/instance:
uuid: "4c2124643d9b4569808d20f561a250f4"
format_stamp: "Formatted at 2026-08-12 06:18:11 on dist-test-slave-7z32"
I20260812 06:18:11.872052 13353 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.001s	sys 0.002s
I20260812 06:18:11.873749 13824 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:18:11.874256 13353 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:11.874393 13353 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root
uuid: "4c2124643d9b4569808d20f561a250f4"
format_stamp: "Formatted at 2026-08-12 06:18:11 on dist-test-slave-7z32"
I20260812 06:18:11.874552 13353 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-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:18:11.885450 13353 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:11.886089 13353 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:11.886561 13353 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:11.887301 13353 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:11.887375 13353 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:11.887446 13353 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:11.887506 13353 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:11.894063 13353 rpc_server.cc:307] RPC server started. Bound to: 127.13.10.65:43131
I20260812 06:18:11.895265 13930 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.10.65:43131 every 8 connection(s)
I20260812 06:18:11.903986 13932 heartbeater.cc:344] Connected to a master server at 127.13.10.126:34927
I20260812 06:18:11.904166 13932 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:11.904520 13932 heartbeater.cc:507] Master 127.13.10.126:34927 requested a full tablet report, sending...
I20260812 06:18:11.906075 13708 ts_manager.cc:194] Registered new tserver with Master: 4c2124643d9b4569808d20f561a250f4 (127.13.10.65:43131)
I20260812 06:18:11.907033 13353 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011822603s
I20260812 06:18:11.907123 13708 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:35568
I20260812 06:18:11.918989 13708 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:35584:
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:18:11.933545 13867 tablet_service.cc:1511] Processing CreateTablet for tablet bfc9e55817d243168810b2dc32ee4941 (DEFAULT_TABLE table=heavy-update-compaction-test [id=cb52b5c261bc4bbd9e48b41d651a34b2]), partition=
I20260812 06:18:11.934128 13867 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet bfc9e55817d243168810b2dc32ee4941. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:11.937031 13948 tablet_bootstrap.cc:492] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Bootstrap starting.
I20260812 06:18:11.938341 13948 tablet_bootstrap.cc:654] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:11.940235 13948 tablet_bootstrap.cc:492] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: No bootstrap required, opened a new log
I20260812 06:18:11.940423 13948 ts_tablet_manager.cc:1403] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Time spent bootstrapping tablet: real 0.004s	user 0.003s	sys 0.000s
I20260812 06:18:11.941006 13948 raft_consensus.cc:359] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c2124643d9b4569808d20f561a250f4" member_type: VOTER last_known_addr { host: "127.13.10.65" port: 43131 } }
I20260812 06:18:11.941174 13948 raft_consensus.cc:385] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:11.941233 13948 raft_consensus.cc:740] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4c2124643d9b4569808d20f561a250f4, State: Initialized, Role: FOLLOWER
I20260812 06:18:11.941437 13948 consensus_queue.cc:260] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4 [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: "4c2124643d9b4569808d20f561a250f4" member_type: VOTER last_known_addr { host: "127.13.10.65" port: 43131 } }
I20260812 06:18:11.941567 13948 raft_consensus.cc:399] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:11.941627 13948 raft_consensus.cc:493] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:11.941681 13948 raft_consensus.cc:3060] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:11.943012 13948 raft_consensus.cc:515] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c2124643d9b4569808d20f561a250f4" member_type: VOTER last_known_addr { host: "127.13.10.65" port: 43131 } }
I20260812 06:18:11.943238 13948 leader_election.cc:304] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4 [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: 4c2124643d9b4569808d20f561a250f4; no voters: 
I20260812 06:18:11.943565 13948 leader_election.cc:290] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:11.943828 13950 raft_consensus.cc:2804] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:11.944070 13932 heartbeater.cc:499] Master 127.13.10.126:34927 was elected leader, sending a full tablet report...
I20260812 06:18:11.944015 13948 ts_tablet_manager.cc:1434] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Time spent starting tablet: real 0.004s	user 0.001s	sys 0.003s
I20260812 06:18:11.944360 13950 raft_consensus.cc:697] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4 [term 1 LEADER]: Becoming Leader. State: Replica: 4c2124643d9b4569808d20f561a250f4, State: Running, Role: LEADER
I20260812 06:18:11.944586 13950 consensus_queue.cc:237] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4 [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: "4c2124643d9b4569808d20f561a250f4" member_type: VOTER last_known_addr { host: "127.13.10.65" port: 43131 } }
I20260812 06:18:11.947305 13708 catalog_manager.cc:5719] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4 reported cstate change: term changed from 0 to 1, leader changed from <none> to 4c2124643d9b4569808d20f561a250f4 (127.13.10.65). New cstate: current_term: 1 leader_uuid: "4c2124643d9b4569808d20f561a250f4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c2124643d9b4569808d20f561a250f4" member_type: VOTER last_known_addr { host: "127.13.10.65" port: 43131 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:12.038918 13353 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.080s	user 0.018s	sys 0.016s
I20260812 06:18:12.146364 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushMRSOp(bfc9e55817d243168810b2dc32ee4941): perf score=10.125253
I20260812 06:18:12.304517 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushMRSOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.158s	user 0.113s	sys 0.043s Metrics: {"bytes_written":9148636,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":236,"dirs.run_cpu_time_us":328,"dirs.run_wall_time_us":1328,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34250,"lbm_writes_lt_1ms":480,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"spinlock_wait_cycles":16512,"update_count":1115}
I20260812 06:18:12.305344 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling LogGCOp(bfc9e55817d243168810b2dc32ee4941): free 11976772 bytes of WAL
I20260812 06:18:12.305609 13838 log_reader.cc:385] T bfc9e55817d243168810b2dc32ee4941: removed 1 log segments from log reader
I20260812 06:18:12.305660 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000001 (ops 1-6)
I20260812 06:18:12.308661 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: LogGCOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:12.309130 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling UndoDeltaBlockGCOp(bfc9e55817d243168810b2dc32ee4941): 8206537 bytes on disk
I20260812 06:18:12.309664 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: UndoDeltaBlockGCOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4}
I20260812 06:18:12.310420 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.196750
I20260812 06:18:12.323726 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3159080,"delete_count":0,"lbm_write_time_us":4389,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:18:12.324559 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:12.469856 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.145s	user 0.091s	sys 0.053s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487914,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":349,"lbm_read_time_us":11096,"lbm_reads_lt_1ms":368,"lbm_write_time_us":24117,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"thread_start_us":376,"threads_started":5,"update_count":1500}
I20260812 06:18:12.470738 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=6.157687
I20260812 06:18:12.510685 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.040s	user 0.018s	sys 0.009s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12678,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:12.511759 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:12.526497 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.014s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5076,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.527359 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:12.673877 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.146s	user 0.121s	sys 0.024s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487935,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":850,"lbm_read_time_us":9154,"lbm_reads_lt_1ms":372,"lbm_write_time_us":26780,"lbm_writes_lt_1ms":343,"mutex_wait_us":93,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.674780 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=10.126437
I20260812 06:18:12.728116 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.053s	user 0.018s	sys 0.033s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":26193,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.729054 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:12.742321 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4313,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.742955 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:12.905999 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.163s	user 0.129s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1453,"lbm_read_time_us":11829,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27899,"lbm_writes_lt_1ms":443,"mutex_wait_us":423,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":2000}
I20260812 06:18:12.906917 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=10.126437
I20260812 06:18:12.988673 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.081s	user 0.049s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23508,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.989665 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:13.003263 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5164,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.003780 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:13.192363 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.188s	user 0.121s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":702,"lbm_read_time_us":14123,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28867,"lbm_writes_lt_1ms":443,"mutex_wait_us":566,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":36864,"update_count":2000}
I20260812 06:18:13.192981 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=10.126437
I20260812 06:18:13.243073 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.050s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19000,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.243640 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:13.364890 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.121s	user 0.099s	sys 0.020s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16487816,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":136,"lbm_read_time_us":7006,"lbm_reads_lt_1ms":363,"lbm_write_time_us":22132,"lbm_writes_lt_1ms":343,"mutex_wait_us":59,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":1500}
I20260812 06:18:13.365721 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=10.126437
I20260812 06:18:13.411837 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.046s	user 0.034s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18173,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.412568 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:13.545986 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.133s	user 0.096s	sys 0.028s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16487817,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1963,"lbm_read_time_us":7316,"lbm_reads_lt_1ms":363,"lbm_write_time_us":23686,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":1500}
I20260812 06:18:13.546774 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=10.126437
I20260812 06:18:13.593791 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.047s	user 0.018s	sys 0.018s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17169,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.594419 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:13.727686 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.133s	user 0.089s	sys 0.035s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16487818,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":192,"lbm_read_time_us":7145,"lbm_reads_lt_1ms":363,"lbm_write_time_us":25355,"lbm_writes_lt_1ms":343,"mutex_wait_us":112,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1500}
I20260812 06:18:13.728497 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=10.126437
I20260812 06:18:13.779721 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.051s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19269,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.780407 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:13.916555 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.136s	user 0.115s	sys 0.020s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16487817,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1582,"lbm_read_time_us":8354,"lbm_reads_lt_1ms":363,"lbm_write_time_us":26348,"lbm_writes_lt_1ms":343,"mutex_wait_us":416,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:18:13.917526 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=10.126437
I20260812 06:18:13.967273 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.050s	user 0.020s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":24232,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.968245 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:13.980243 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4465,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.980787 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushMRSOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:14.020694 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushMRSOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.040s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":353,"dirs.run_wall_time_us":1839,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2056,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:14.021564 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling LogGCOp(bfc9e55817d243168810b2dc32ee4941): free 120553385 bytes of WAL
I20260812 06:18:14.021858 13838 log_reader.cc:385] T bfc9e55817d243168810b2dc32ee4941: removed 12 log segments from log reader
I20260812 06:18:14.021911 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000002 (ops 7-11)
I20260812 06:18:14.021948 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000003 (ops 12-16)
I20260812 06:18:14.022014 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000004 (ops 17-21)
I20260812 06:18:14.022063 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000005 (ops 22-26)
I20260812 06:18:14.022146 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000006 (ops 27-31)
I20260812 06:18:14.022173 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000007 (ops 32-36)
I20260812 06:18:14.022235 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000008 (ops 37-40)
I20260812 06:18:14.022279 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000009 (ops 41-45)
I20260812 06:18:14.022320 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000010 (ops 46-50)
I20260812 06:18:14.022363 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000011 (ops 51-54)
I20260812 06:18:14.022397 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000012 (ops 55-59)
I20260812 06:18:14.022416 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000013 (ops 60-64)
I20260812 06:18:14.055119 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: LogGCOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.033s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:18:14.055661 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=3.181125
I20260812 06:18:14.076593 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.021s	user 0.013s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":7530,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:14.077364 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling UndoDeltaBlockGCOp(bfc9e55817d243168810b2dc32ee4941): 473 bytes on disk
I20260812 06:18:14.077917 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: UndoDeltaBlockGCOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4}
I20260812 06:18:14.078478 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:14.092772 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.014s	user 0.007s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4917,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:14.095350 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:14.325230 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.230s	user 0.168s	sys 0.051s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795398,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2024,"lbm_read_time_us":15970,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35118,"lbm_writes_lt_1ms":643,"mutex_wait_us":544,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15872,"thread_start_us":97,"threads_started":1,"update_count":3000}
I20260812 06:18:14.326505 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=14.095187
I20260812 06:18:14.406600 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.080s	user 0.020s	sys 0.047s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":25459,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.407456 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:14.425395 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.018s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7316,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.426095 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:14.679224 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.253s	user 0.167s	sys 0.085s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692761,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1400,"lbm_read_time_us":20667,"lbm_reads_lt_1ms":572,"lbm_write_time_us":42048,"lbm_writes_lt_1ms":543,"mutex_wait_us":370,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:18:14.680114 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=14.095187
I20260812 06:18:14.757332 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.077s	user 0.030s	sys 0.043s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":29852,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.758260 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:14.779865 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.021s	user 0.020s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7757,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.780727 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:14.988049 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.207s	user 0.131s	sys 0.075s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692760,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":415,"lbm_read_time_us":13970,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34130,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:18:14.988937 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=10.126437
I20260812 06:18:15.037125 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.048s	user 0.013s	sys 0.032s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19786,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:15.038355 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:15.053913 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6084,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.054661 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:15.257236 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.202s	user 0.146s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":474,"lbm_read_time_us":12032,"lbm_reads_lt_1ms":464,"lbm_write_time_us":38320,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25216,"update_count":2000}
I20260812 06:18:15.258148 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=14.095187
I20260812 06:18:15.321591 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.063s	user 0.029s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27951,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.322345 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:15.339180 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6132,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.339859 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:15.498472 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.158s	user 0.114s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":778,"lbm_read_time_us":11689,"lbm_reads_lt_1ms":568,"lbm_write_time_us":31143,"lbm_writes_lt_1ms":543,"mutex_wait_us":104,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:18:15.499265 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=10.126437
I20260812 06:18:15.556689 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.057s	user 0.029s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20199,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:15.557534 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:15.575304 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.018s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6616,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.576092 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:15.749908 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.173s	user 0.123s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1087,"lbm_read_time_us":14016,"lbm_reads_lt_1ms":472,"lbm_write_time_us":35083,"lbm_writes_lt_1ms":443,"mutex_wait_us":437,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2000}
I20260812 06:18:15.750861 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=11.118625
I20260812 06:18:15.808260 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.057s	user 0.040s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":20680,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:15.809294 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:15.830405 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.021s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6226,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:15.831453 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushMRSOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:15.887125 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushMRSOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.055s	user 0.039s	sys 0.005s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":113,"dirs.run_cpu_time_us":475,"dirs.run_wall_time_us":2062,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2611,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:15.888573 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling UndoDeltaBlockGCOp(bfc9e55817d243168810b2dc32ee4941): 473 bytes on disk
I20260812 06:18:15.889379 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: UndoDeltaBlockGCOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4}
I20260812 06:18:15.890202 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=3.181125
I20260812 06:18:15.905754 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6078,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:15.906479 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling LogGCOp(bfc9e55817d243168810b2dc32ee4941): free 121006383 bytes of WAL
I20260812 06:18:15.906785 13838 log_reader.cc:385] T bfc9e55817d243168810b2dc32ee4941: removed 12 log segments from log reader
I20260812 06:18:15.906916 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000014 (ops 65-69)
I20260812 06:18:15.906996 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000015 (ops 70-74)
I20260812 06:18:15.907061 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000016 (ops 75-79)
I20260812 06:18:15.907106 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000017 (ops 80-84)
I20260812 06:18:15.907151 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000018 (ops 85-89)
I20260812 06:18:15.907192 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000019 (ops 90-94)
I20260812 06:18:15.907217 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000020 (ops 95-98)
I20260812 06:18:15.907264 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000021 (ops 99-103)
I20260812 06:18:15.907305 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000022 (ops 104-108)
I20260812 06:18:15.907346 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000023 (ops 109-113)
I20260812 06:18:15.907385 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000024 (ops 114-118)
I20260812 06:18:15.907431 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000025 (ops 119-123)
I20260812 06:18:15.941742 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: LogGCOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.035s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:18:15.942409 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:15.969676 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.027s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5829,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.970556 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:15.983492 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4198,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:15.984251 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:16.247985 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.264s	user 0.192s	sys 0.071s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32897922,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":330,"lbm_read_time_us":21395,"lbm_reads_lt_1ms":775,"lbm_write_time_us":43864,"lbm_writes_lt_1ms":743,"mutex_wait_us":19,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":19072,"thread_start_us":113,"threads_started":1,"update_count":3500}
I20260812 06:18:16.249477 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=14.095187
I20260812 06:18:16.317920 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.067s	user 0.045s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":30575,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.319013 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:16.339597 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.020s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7627,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.340332 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:16.536707 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.196s	user 0.154s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":586,"lbm_read_time_us":12847,"lbm_reads_lt_1ms":564,"lbm_write_time_us":36752,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2500}
I20260812 06:18:16.537796 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=14.095187
I20260812 06:18:16.603080 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.065s	user 0.035s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24340,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.604132 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:16.621594 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.017s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6107,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.622274 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:16.828217 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.206s	user 0.143s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692761,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":536,"lbm_read_time_us":14054,"lbm_reads_lt_1ms":572,"lbm_write_time_us":37215,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2500}
I20260812 06:18:16.829244 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=14.095187
I20260812 06:18:16.912254 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.083s	user 0.044s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":30658,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.913024 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:16.929978 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.017s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5694,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.930895 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:17.161358 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.230s	user 0.165s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692761,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2902,"lbm_read_time_us":15938,"lbm_reads_lt_1ms":564,"lbm_write_time_us":38275,"lbm_writes_lt_1ms":543,"mutex_wait_us":622,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:18:17.162523 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=14.095187
I20260812 06:18:17.229771 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.067s	user 0.039s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":30903,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.230953 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:17.253181 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.022s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5473,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.254226 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:17.456883 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.202s	user 0.145s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":361,"lbm_read_time_us":12575,"lbm_reads_lt_1ms":564,"lbm_write_time_us":35394,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2500}
I20260812 06:18:17.457643 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=14.095187
I20260812 06:18:17.541417 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.083s	user 0.028s	sys 0.050s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":30482,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.542234 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:17.558967 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.016s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6327,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.559640 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:17.781244 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.221s	user 0.143s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":319,"lbm_read_time_us":17834,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35552,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":42752,"update_count":2500}
I20260812 06:18:17.782212 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=14.095187
I20260812 06:18:17.858526 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.076s	user 0.033s	sys 0.034s Metrics: {"bytes_written":16409889,"delete_count":0,"lbm_write_time_us":27674,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.859593 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:17.874145 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5714,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.874996 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushMRSOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:17.930567 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushMRSOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.055s	user 0.028s	sys 0.008s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":1500,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2161,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:17.931787 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling LogGCOp(bfc9e55817d243168810b2dc32ee4941): free 137181831 bytes of WAL
I20260812 06:18:17.932189 13838 log_reader.cc:385] T bfc9e55817d243168810b2dc32ee4941: removed 14 log segments from log reader
I20260812 06:18:17.932281 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000026 (ops 124-128)
I20260812 06:18:17.932334 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000027 (ops 129-133)
I20260812 06:18:17.932396 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000028 (ops 134-138)
I20260812 06:18:17.932439 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000029 (ops 139-142)
I20260812 06:18:17.932479 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000030 (ops 143-147)
I20260812 06:18:17.932513 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000031 (ops 148-152)
I20260812 06:18:17.932552 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000032 (ops 153-156)
I20260812 06:18:17.932590 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000033 (ops 157-161)
I20260812 06:18:17.932631 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000034 (ops 162-166)
I20260812 06:18:17.932672 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000035 (ops 167-170)
I20260812 06:18:17.932713 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000036 (ops 171-175)
I20260812 06:18:17.932756 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000037 (ops 176-180)
I20260812 06:18:17.932830 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000038 (ops 181-184)
I20260812 06:18:17.932896 13838 log.cc:1079] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: Deleting log segment in path: /tmp/dist-test-taskQvk8An/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515484685348-13353-0/minicluster-data/ts-0-root/wals/bfc9e55817d243168810b2dc32ee4941/wal-000000039 (ops 185-189)
I20260812 06:18:17.973969 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: LogGCOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.042s	user 0.000s	sys 0.039s Metrics: {}
I20260812 06:18:17.974809 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=3.181125
I20260812 06:18:18.002054 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.027s	user 0.005s	sys 0.016s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":10027,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:18.002972 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling UndoDeltaBlockGCOp(bfc9e55817d243168810b2dc32ee4941): 493 bytes on disk
I20260812 06:18:18.003597 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: UndoDeltaBlockGCOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4}
I20260812 06:18:18.004294 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=2.188937
I20260812 06:18:18.021637 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6512,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:18.022284 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941): perf score=1.000000
I20260812 06:18:18.250070 13353 heavy-update-compaction-itest.cc:229] Time spent updating: real 6.211s	user 2.200s	sys 0.256s
I20260812 06:18:18.335225 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: MajorDeltaCompactionOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.313s	user 0.221s	sys 0.091s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32897798,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":22702,"lbm_reads_lt_1ms":762,"lbm_write_time_us":58846,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":3500}
I20260812 06:18:18.336059 13934 maintenance_manager.cc:419] P 4c2124643d9b4569808d20f561a250f4: Scheduling FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941): perf score=14.095187
I20260812 06:18:18.365144 13353 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.115s	user 0.001s	sys 0.000s
I20260812 06:18:18.367360 13353 tablet_server.cc:179] TabletServer@127.13.10.65:0 shutting down...
I20260812 06:18:18.397012 13838 maintenance_manager.cc:643] P 4c2124643d9b4569808d20f561a250f4: FlushDeltaMemStoresOp(bfc9e55817d243168810b2dc32ee4941) complete. Timing: real 0.061s	user 0.039s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27558,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.398221 13353 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:18.398623 13353 tablet_replica.cc:333] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4: stopping tablet replica
I20260812 06:18:18.398836 13353 raft_consensus.cc:2243] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:18.399080 13353 raft_consensus.cc:2272] T bfc9e55817d243168810b2dc32ee4941 P 4c2124643d9b4569808d20f561a250f4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:18.404980 13353 tablet_server.cc:196] TabletServer@127.13.10.65:0 shutdown complete.
I20260812 06:18:18.412271 13353 master.cc:562] Master@127.13.10.126:34927 shutting down...
I20260812 06:18:18.419201 13353 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:18.419473 13353 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:18.419538 13353 tablet_replica.cc:333] T 00000000000000000000000000000000 P a6dcca23c4b642abb07379e84212d762: stopping tablet replica
I20260812 06:18:18.433122 13353 master.cc:584] Master@127.13.10.126:34927 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6809 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (13847 ms total)

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