[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:07.885936 22829 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.75.126:33311
I20260812 06:19:07.886792 22829 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:07.887326 22829 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:07.893147 22829 server_base.cc:1061] running on GCE node
W20260812 06:19:07.893193 22841 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:07.893306 22838 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:07.893514 22837 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:07.893957 22829 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:07.894045 22829 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:07.894085 22829 hybrid_clock.cc:648] HybridClock initialized: now 1786515547894083 us; error 0 us; skew 500 ppm
I20260812 06:19:07.895618 22829 webserver.cc:533] Webserver started at http://127.22.75.126:41107/ using document root <none> and password file <none>
I20260812 06:19:07.896077 22829 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:07.896135 22829 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:07.896339 22829 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:07.897889 22829 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/master-0-root/instance:
uuid: "88a8986ac38e4e9f86c4692e0e2b3706"
format_stamp: "Formatted at 2026-08-12 06:19:07 on dist-test-slave-42z9"
I20260812 06:19:07.900914 22829 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:07.902746 22857 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:07.903604 22829 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:07.903695 22829 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/master-0-root
uuid: "88a8986ac38e4e9f86c4692e0e2b3706"
format_stamp: "Formatted at 2026-08-12 06:19:07 on dist-test-slave-42z9"
I20260812 06:19:07.903779 22829 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:07.915657 22829 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:07.916146 22829 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:07.916280 22829 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:07.922885 22829 rpc_server.cc:307] RPC server started. Bound to: 127.22.75.126:33311
I20260812 06:19:07.922895 22945 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.75.126:33311 every 8 connection(s)
I20260812 06:19:07.924810 22949 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:07.929698 22949 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706: Bootstrap starting.
I20260812 06:19:07.931778 22949 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:07.932574 22949 log.cc:826] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:07.934026 22949 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706: No bootstrap required, opened a new log
I20260812 06:19:07.936493 22949 raft_consensus.cc:359] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "88a8986ac38e4e9f86c4692e0e2b3706" member_type: VOTER }
I20260812 06:19:07.936641 22949 raft_consensus.cc:385] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:07.936702 22949 raft_consensus.cc:740] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 88a8986ac38e4e9f86c4692e0e2b3706, State: Initialized, Role: FOLLOWER
I20260812 06:19:07.937240 22949 consensus_queue.cc:260] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [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: "88a8986ac38e4e9f86c4692e0e2b3706" member_type: VOTER }
I20260812 06:19:07.937381 22949 raft_consensus.cc:399] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:07.937462 22949 raft_consensus.cc:493] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:07.937587 22949 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:07.938267 22949 raft_consensus.cc:515] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "88a8986ac38e4e9f86c4692e0e2b3706" member_type: VOTER }
I20260812 06:19:07.938648 22949 leader_election.cc:304] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [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: 88a8986ac38e4e9f86c4692e0e2b3706; no voters: 
I20260812 06:19:07.938899 22949 leader_election.cc:290] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:07.939033 22956 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:07.939237 22956 raft_consensus.cc:697] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [term 1 LEADER]: Becoming Leader. State: Replica: 88a8986ac38e4e9f86c4692e0e2b3706, State: Running, Role: LEADER
I20260812 06:19:07.939631 22956 consensus_queue.cc:237] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [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: "88a8986ac38e4e9f86c4692e0e2b3706" member_type: VOTER }
I20260812 06:19:07.939760 22949 sys_catalog.cc:565] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:07.941231 22958 sys_catalog.cc:455] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 88a8986ac38e4e9f86c4692e0e2b3706. Latest consensus state: current_term: 1 leader_uuid: "88a8986ac38e4e9f86c4692e0e2b3706" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "88a8986ac38e4e9f86c4692e0e2b3706" member_type: VOTER } }
I20260812 06:19:07.941334 22958 sys_catalog.cc:458] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:07.941285 22957 sys_catalog.cc:455] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "88a8986ac38e4e9f86c4692e0e2b3706" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "88a8986ac38e4e9f86c4692e0e2b3706" member_type: VOTER } }
I20260812 06:19:07.941376 22957 sys_catalog.cc:458] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:07.941679 22982 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:07.941823 22829 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:07.943622 22982 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:07.947760 22982 catalog_manager.cc:1383] Generated new cluster ID: 911d724308cf4a5da558b015898f4e3e
I20260812 06:19:07.947817 22982 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:07.954244 22982 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:07.955224 22982 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:07.961416 22982 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706: Generated new TSK 0
I20260812 06:19:07.961999 22982 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:07.974135 22829 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:07.976464 23006 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:07.976531 22992 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:07.976514 22998 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:07.976629 22829 server_base.cc:1061] running on GCE node
I20260812 06:19:07.976886 22829 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:07.976938 22829 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:07.976959 22829 hybrid_clock.cc:648] HybridClock initialized: now 1786515547976959 us; error 0 us; skew 500 ppm
I20260812 06:19:07.977837 22829 webserver.cc:533] Webserver started at http://127.22.75.65:35537/ using document root <none> and password file <none>
I20260812 06:19:07.977990 22829 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:07.978044 22829 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:07.978125 22829 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:07.978519 22829 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/instance:
uuid: "fa57e73fc03e4ce2ac81bde66c631660"
format_stamp: "Formatted at 2026-08-12 06:19:07 on dist-test-slave-42z9"
I20260812 06:19:07.980227 22829 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:07.981230 23016 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:07.981489 22829 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:07.981557 22829 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root
uuid: "fa57e73fc03e4ce2ac81bde66c631660"
format_stamp: "Formatted at 2026-08-12 06:19:07 on dist-test-slave-42z9"
I20260812 06:19:07.981621 22829 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:07.988080 22829 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:07.988415 22829 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:07.988797 22829 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:07.989568 22829 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:07.989617 22829 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:07.989661 22829 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:07.989691 22829 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:07.995208 22829 rpc_server.cc:307] RPC server started. Bound to: 127.22.75.65:35025
I20260812 06:19:07.995262 23140 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.75.65:35025 every 8 connection(s)
I20260812 06:19:08.007087 23141 heartbeater.cc:344] Connected to a master server at 127.22.75.126:33311
I20260812 06:19:08.007311 23141 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:08.007798 23141 heartbeater.cc:507] Master 127.22.75.126:33311 requested a full tablet report, sending...
I20260812 06:19:08.009219 22883 ts_manager.cc:194] Registered new tserver with Master: fa57e73fc03e4ce2ac81bde66c631660 (127.22.75.65:35025)
I20260812 06:19:08.010064 22829 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014307684s
I20260812 06:19:08.010710 22883 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37514
I20260812 06:19:08.018891 22883 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37530:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:08.032629 23070 tablet_service.cc:1511] Processing CreateTablet for tablet 414367c89dac4c0f9302cd1724e95ceb (DEFAULT_TABLE table=heavy-update-compaction-test [id=2ea6169499ec42a28fb2597083193972]), partition=
I20260812 06:19:08.033082 23070 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 414367c89dac4c0f9302cd1724e95ceb. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:08.035765 23159 tablet_bootstrap.cc:492] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Bootstrap starting.
I20260812 06:19:08.036705 23159 tablet_bootstrap.cc:654] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:08.037730 23159 tablet_bootstrap.cc:492] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: No bootstrap required, opened a new log
I20260812 06:19:08.037813 23159 ts_tablet_manager.cc:1403] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:08.038197 23159 raft_consensus.cc:359] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fa57e73fc03e4ce2ac81bde66c631660" member_type: VOTER last_known_addr { host: "127.22.75.65" port: 35025 } }
I20260812 06:19:08.038292 23159 raft_consensus.cc:385] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:08.038314 23159 raft_consensus.cc:740] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fa57e73fc03e4ce2ac81bde66c631660, State: Initialized, Role: FOLLOWER
I20260812 06:19:08.038445 23159 consensus_queue.cc:260] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660 [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: "fa57e73fc03e4ce2ac81bde66c631660" member_type: VOTER last_known_addr { host: "127.22.75.65" port: 35025 } }
I20260812 06:19:08.038522 23159 raft_consensus.cc:399] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:08.038558 23159 raft_consensus.cc:493] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:08.038647 23159 raft_consensus.cc:3060] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:08.039559 23159 raft_consensus.cc:515] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fa57e73fc03e4ce2ac81bde66c631660" member_type: VOTER last_known_addr { host: "127.22.75.65" port: 35025 } }
I20260812 06:19:08.039701 23159 leader_election.cc:304] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660 [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: fa57e73fc03e4ce2ac81bde66c631660; no voters: 
I20260812 06:19:08.039884 23159 leader_election.cc:290] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:08.040031 23164 raft_consensus.cc:2804] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:08.040278 23159 ts_tablet_manager.cc:1434] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:08.040314 23164 raft_consensus.cc:697] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660 [term 1 LEADER]: Becoming Leader. State: Replica: fa57e73fc03e4ce2ac81bde66c631660, State: Running, Role: LEADER
I20260812 06:19:08.040655 23141 heartbeater.cc:499] Master 127.22.75.126:33311 was elected leader, sending a full tablet report...
I20260812 06:19:08.040515 23164 consensus_queue.cc:237] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660 [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: "fa57e73fc03e4ce2ac81bde66c631660" member_type: VOTER last_known_addr { host: "127.22.75.65" port: 35025 } }
I20260812 06:19:08.043503 22883 catalog_manager.cc:5719] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660 reported cstate change: term changed from 0 to 1, leader changed from <none> to fa57e73fc03e4ce2ac81bde66c631660 (127.22.75.65). New cstate: current_term: 1 leader_uuid: "fa57e73fc03e4ce2ac81bde66c631660" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fa57e73fc03e4ce2ac81bde66c631660" member_type: VOTER last_known_addr { host: "127.22.75.65" port: 35025 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:08.105055 22829 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.014s	sys 0.012s
I20260812 06:19:08.246460 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushMRSOp(414367c89dac4c0f9302cd1724e95ceb): perf score=19.054940
I20260812 06:19:08.420127 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushMRSOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.173s	user 0.125s	sys 0.044s Metrics: {"bytes_written":17640626,"cfile_init":1,"compiler_manager_pool.queue_time_us":195,"delete_count":0,"dirs.queue_time_us":37,"dirs.run_cpu_time_us":182,"dirs.run_wall_time_us":759,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41756,"lbm_writes_lt_1ms":897,"mutex_wait_us":214,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":322432,"thread_start_us":100,"threads_started":1,"update_count":2150}
I20260812 06:19:08.421340 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling LogGCOp(414367c89dac4c0f9302cd1724e95ceb): free 20743880 bytes of WAL
I20260812 06:19:08.421825 23027 log_reader.cc:385] T 414367c89dac4c0f9302cd1724e95ceb: removed 2 log segments from log reader
I20260812 06:19:08.421962 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000001 (ops 1-6)
I20260812 06:19:08.422060 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000002 (ops 7-11)
I20260812 06:19:08.427321 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: LogGCOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:08.427721 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling UndoDeltaBlockGCOp(414367c89dac4c0f9302cd1724e95ceb): 16821648 bytes on disk
I20260812 06:19:08.428467 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: UndoDeltaBlockGCOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:19:08.428968 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.196750
I20260812 06:19:08.442222 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.013s	user 0.009s	sys 0.001s Metrics: {"bytes_written":2871909,"delete_count":0,"lbm_write_time_us":3920,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:19:08.442600 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:08.454910 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.012s	user 0.001s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4776,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:08.455256 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:08.633728 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.178s	user 0.111s	sys 0.056s Metrics: {"cfile_cache_miss":623,"cfile_cache_miss_bytes":28507935,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":616,"lbm_read_time_us":11917,"lbm_reads_lt_1ms":659,"lbm_write_time_us":30435,"lbm_writes_lt_1ms":633,"peak_mem_usage":74091738,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":314,"threads_started":5,"update_count":2950}
I20260812 06:19:08.634186 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=14.095187
I20260812 06:19:08.685837 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.051s	user 0.028s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22297,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:08.686275 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:08.700623 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5465,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.701068 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:08.862814 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.162s	user 0.099s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":527,"lbm_read_time_us":10524,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27499,"lbm_writes_lt_1ms":543,"mutex_wait_us":281,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:19:08.863245 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=14.095187
I20260812 06:19:08.911221 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.048s	user 0.019s	sys 0.026s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18387,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:08.911737 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:08.926433 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.015s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5697,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.926852 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:09.089746 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.163s	user 0.119s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1138,"lbm_read_time_us":11776,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27668,"lbm_writes_lt_1ms":543,"mutex_wait_us":309,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:19:09.090314 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=11.118625
I20260812 06:19:09.126371 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.036s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15128,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:09.126852 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:09.159708 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.033s	user 0.008s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4224,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:09.160235 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:09.173066 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5114,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.173516 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:09.331316 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.158s	user 0.123s	sys 0.033s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815796,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":128,"lbm_read_time_us":10703,"lbm_reads_lt_1ms":573,"lbm_write_time_us":25379,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:19:09.331939 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=11.118625
I20260812 06:19:09.361822 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.030s	user 0.014s	sys 0.015s Metrics: {"bytes_written":12635684,"delete_count":0,"lbm_write_time_us":12420,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1540}
I20260812 06:19:09.362337 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:09.375742 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":5001,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:19:09.376240 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:09.493055 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.117s	user 0.088s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713266,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":514,"lbm_read_time_us":7833,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22900,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2000}
I20260812 06:19:09.493609 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=10.126437
I20260812 06:19:09.530294 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.036s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17040,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:09.530766 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:09.545408 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5716,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.546104 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushMRSOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:09.573499 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushMRSOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.027s	user 0.020s	sys 0.005s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":49,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":1153,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1484,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:09.574256 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling LogGCOp(414367c89dac4c0f9302cd1724e95ceb): free 112239271 bytes of WAL
I20260812 06:19:09.574460 23027 log_reader.cc:385] T 414367c89dac4c0f9302cd1724e95ceb: removed 11 log segments from log reader
I20260812 06:19:09.574503 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000003 (ops 12-16)
I20260812 06:19:09.574530 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000004 (ops 17-20)
I20260812 06:19:09.574568 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000005 (ops 21-25)
I20260812 06:19:09.574602 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000006 (ops 26-30)
I20260812 06:19:09.574636 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000007 (ops 31-35)
I20260812 06:19:09.574667 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000008 (ops 36-40)
I20260812 06:19:09.574698 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000009 (ops 41-45)
I20260812 06:19:09.574729 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000010 (ops 46-50)
I20260812 06:19:09.574760 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000011 (ops 51-55)
I20260812 06:19:09.574791 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000012 (ops 56-60)
I20260812 06:19:09.574822 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000013 (ops 61-65)
I20260812 06:19:09.594537 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: LogGCOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.020s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:19:09.594966 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling UndoDeltaBlockGCOp(414367c89dac4c0f9302cd1724e95ceb): 462 bytes on disk
I20260812 06:19:09.595357 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: UndoDeltaBlockGCOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:09.595885 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=4.173312
I20260812 06:19:09.609062 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":5784657,"delete_count":0,"lbm_write_time_us":5277,"lbm_writes_lt_1ms":144,"reinsert_count":0,"update_count":705}
I20260812 06:19:09.609460 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling LogGCOp(414367c89dac4c0f9302cd1724e95ceb): free 8767174 bytes of WAL
I20260812 06:19:09.609663 23027 log_reader.cc:385] T 414367c89dac4c0f9302cd1724e95ceb: removed 1 log segments from log reader
I20260812 06:19:09.609707 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000014 (ops 66-70)
I20260812 06:19:09.611022 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: LogGCOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:09.611287 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.196750
I20260812 06:19:09.619956 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.009s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2420629,"delete_count":0,"lbm_write_time_us":2735,"lbm_writes_lt_1ms":62,"reinsert_count":0,"update_count":295}
I20260812 06:19:09.620430 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:09.771579 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.151s	user 0.102s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918296,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":772,"lbm_read_time_us":9551,"lbm_reads_lt_1ms":666,"lbm_write_time_us":30579,"lbm_writes_lt_1ms":643,"mutex_wait_us":459,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":71,"threads_started":1,"update_count":3000}
I20260812 06:19:09.772125 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=14.095187
I20260812 06:19:09.813097 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.041s	user 0.018s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17686,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:09.813630 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:09.826325 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4581,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.826776 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:09.984973 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.158s	user 0.102s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1156,"lbm_read_time_us":10783,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29455,"lbm_writes_lt_1ms":543,"mutex_wait_us":269,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:09.985487 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=14.095187
I20260812 06:19:10.030755 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.045s	user 0.032s	sys 0.008s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17595,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.031224 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:10.041314 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3909,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.041867 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:10.193641 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.152s	user 0.123s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2003,"lbm_read_time_us":10960,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28030,"lbm_writes_lt_1ms":543,"mutex_wait_us":1350,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2500}
I20260812 06:19:10.194279 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=11.118625
I20260812 06:19:10.239979 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.046s	user 0.026s	sys 0.017s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18467,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:10.240475 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:10.256721 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.016s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3664,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.257227 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:10.265980 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3084,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:10.266525 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:10.407444 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.141s	user 0.103s	sys 0.034s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815795,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":782,"lbm_read_time_us":9183,"lbm_reads_lt_1ms":573,"lbm_write_time_us":24578,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":57472,"update_count":2500}
I20260812 06:19:10.408078 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=11.118625
I20260812 06:19:10.439889 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.032s	user 0.027s	sys 0.002s Metrics: {"bytes_written":13456167,"delete_count":0,"lbm_write_time_us":12858,"lbm_writes_lt_1ms":331,"mutex_wait_us":745,"reinsert_count":0,"update_count":1640}
I20260812 06:19:10.440362 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.196750
I20260812 06:19:10.462795 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.022s	user 0.000s	sys 0.007s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":3170,"lbm_writes_lt_1ms":75,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":360}
I20260812 06:19:10.463280 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:10.472887 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3465,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.473315 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:10.632808 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.159s	user 0.105s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815776,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":3435,"lbm_read_time_us":10321,"lbm_reads_lt_1ms":573,"lbm_write_time_us":25393,"lbm_writes_lt_1ms":543,"mutex_wait_us":2873,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:19:10.633404 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=14.095187
I20260812 06:19:10.683748 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.050s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20476,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.684238 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:10.693892 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3674,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.694319 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:10.853183 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.159s	user 0.106s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":197,"lbm_read_time_us":11641,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25993,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:10.853785 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=14.095187
I20260812 06:19:10.906405 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.052s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16258,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.906898 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:10.916816 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3826,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.917209 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushMRSOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:10.957008 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushMRSOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.040s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":45,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":1106,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1495,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:10.957779 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling LogGCOp(414367c89dac4c0f9302cd1724e95ceb): free 124257260 bytes of WAL
I20260812 06:19:10.957988 23027 log_reader.cc:385] T 414367c89dac4c0f9302cd1724e95ceb: removed 12 log segments from log reader
I20260812 06:19:10.958035 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000015 (ops 71-75)
I20260812 06:19:10.958066 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000016 (ops 76-80)
I20260812 06:19:10.958101 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000017 (ops 81-85)
I20260812 06:19:10.958124 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000018 (ops 86-90)
I20260812 06:19:10.958156 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000019 (ops 91-95)
I20260812 06:19:10.958189 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000020 (ops 96-100)
I20260812 06:19:10.958220 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000021 (ops 101-105)
I20260812 06:19:10.958250 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000022 (ops 106-110)
I20260812 06:19:10.958281 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000023 (ops 111-114)
I20260812 06:19:10.958312 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000024 (ops 115-119)
I20260812 06:19:10.958343 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000025 (ops 120-124)
I20260812 06:19:10.958382 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000026 (ops 125-129)
I20260812 06:19:10.980527 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: LogGCOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.023s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:19:10.980978 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling UndoDeltaBlockGCOp(414367c89dac4c0f9302cd1724e95ceb): 482 bytes on disk
I20260812 06:19:10.981488 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: UndoDeltaBlockGCOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:19:10.982084 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=3.181125
I20260812 06:19:11.003055 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.021s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6560,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:11.003490 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:11.012389 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3228,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:11.012984 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:11.235821 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.223s	user 0.163s	sys 0.056s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":226,"lbm_read_time_us":14853,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37171,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1152,"thread_start_us":68,"threads_started":1,"update_count":3500}
I20260812 06:19:11.236282 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=15.087375
I20260812 06:19:11.282123 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.046s	user 0.038s	sys 0.007s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":19735,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:11.285318 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:11.297873 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3758,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.298259 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:11.307122 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3307,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:11.307488 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:11.470294 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.163s	user 0.133s	sys 0.028s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918203,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":336,"lbm_read_time_us":12108,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32569,"lbm_writes_lt_1ms":643,"mutex_wait_us":56,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":25728,"update_count":3000}
I20260812 06:19:11.470932 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=14.095187
I20260812 06:19:11.527535 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.056s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23188,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:11.528091 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:11.548983 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.021s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5677,"lbm_writes_lt_1ms":103,"mutex_wait_us":31,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.549551 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:11.697429 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.148s	user 0.124s	sys 0.022s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":546,"lbm_read_time_us":9909,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27044,"lbm_writes_lt_1ms":543,"mutex_wait_us":297,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":110208,"update_count":2500}
I20260812 06:19:11.697984 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=14.095187
I20260812 06:19:11.736285 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.038s	user 0.027s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17033,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:11.737780 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:11.890470 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.153s	user 0.105s	sys 0.037s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":551,"lbm_read_time_us":9750,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24781,"lbm_writes_lt_1ms":443,"mutex_wait_us":219,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:19:11.893235 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=14.095187
I20260812 06:19:11.936856 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.043s	user 0.036s	sys 0.003s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18635,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:11.937286 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:12.064755 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.127s	user 0.113s	sys 0.012s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":153,"lbm_read_time_us":6987,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24345,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:12.065340 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=11.118625
I20260812 06:19:12.104851 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.039s	user 0.027s	sys 0.009s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16397,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:12.105597 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:12.126067 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.020s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4302,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:12.126487 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:12.135797 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3415,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.136195 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:12.272202 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.136s	user 0.111s	sys 0.024s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":323,"lbm_read_time_us":9234,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26469,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:19:12.272816 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=10.126437
I20260812 06:19:12.303711 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.030s	user 0.020s	sys 0.007s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":12472,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.304185 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:12.314272 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3690,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.314904 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushMRSOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:12.344940 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushMRSOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.030s	user 0.025s	sys 0.002s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1195,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1437,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:12.345710 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling LogGCOp(414367c89dac4c0f9302cd1724e95ceb): free 128414664 bytes of WAL
I20260812 06:19:12.345947 23027 log_reader.cc:385] T 414367c89dac4c0f9302cd1724e95ceb: removed 13 log segments from log reader
I20260812 06:19:12.346014 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000027 (ops 130-134)
I20260812 06:19:12.346052 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000028 (ops 135-138)
I20260812 06:19:12.346086 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000029 (ops 139-143)
I20260812 06:19:12.346117 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000030 (ops 144-148)
I20260812 06:19:12.346148 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000031 (ops 149-152)
I20260812 06:19:12.346177 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000032 (ops 153-157)
I20260812 06:19:12.346207 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000033 (ops 158-162)
I20260812 06:19:12.346237 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000034 (ops 163-166)
I20260812 06:19:12.346267 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000035 (ops 167-171)
I20260812 06:19:12.346297 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000036 (ops 172-176)
I20260812 06:19:12.346325 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000037 (ops 177-181)
I20260812 06:19:12.346354 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000038 (ops 182-186)
I20260812 06:19:12.346383 23027 log.cc:1079] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/414367c89dac4c0f9302cd1724e95ceb/wal-000000039 (ops 187-190)
I20260812 06:19:12.366608 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: LogGCOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.021s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:19:12.367048 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling UndoDeltaBlockGCOp(414367c89dac4c0f9302cd1724e95ceb): 473 bytes on disk
I20260812 06:19:12.367554 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: UndoDeltaBlockGCOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:19:12.368183 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:12.381860 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4093,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.382287 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=2.188937
I20260812 06:19:12.396587 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.014s	user 0.001s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5257,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.397147 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:12.503733 22829 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.399s	user 1.637s	sys 0.135s
I20260812 06:19:12.548947 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.152s	user 0.130s	sys 0.019s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918336,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":10673,"lbm_reads_lt_1ms":670,"lbm_write_time_us":28624,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":3000}
I20260812 06:19:12.549425 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb): perf score=10.126437
I20260812 06:19:12.576225 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: FlushDeltaMemStoresOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.027s	user 0.023s	sys 0.001s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":10787,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.576707 23142 maintenance_manager.cc:419] P fa57e73fc03e4ce2ac81bde66c631660: Scheduling MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb): perf score=1.000000
I20260812 06:19:12.578974 22829 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.075s	user 0.002s	sys 0.000s
I20260812 06:19:12.579552 22829 tablet_server.cc:179] TabletServer@127.22.75.65:0 shutting down...
I20260812 06:19:12.658955 23027 maintenance_manager.cc:643] P fa57e73fc03e4ce2ac81bde66c631660: MajorDeltaCompactionOp(414367c89dac4c0f9302cd1724e95ceb) complete. Timing: real 0.082s	user 0.065s	sys 0.016s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16610741,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":518,"lbm_read_time_us":5911,"lbm_reads_lt_1ms":367,"lbm_write_time_us":14575,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.659739 22829 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:12.660090 22829 tablet_replica.cc:333] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660: stopping tablet replica
I20260812 06:19:12.660300 22829 raft_consensus.cc:2243] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:12.660517 22829 raft_consensus.cc:2272] T 414367c89dac4c0f9302cd1724e95ceb P fa57e73fc03e4ce2ac81bde66c631660 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:12.675525 22829 tablet_server.cc:196] TabletServer@127.22.75.65:0 shutdown complete.
I20260812 06:19:12.690600 22829 master.cc:562] Master@127.22.75.126:33311 shutting down...
I20260812 06:19:12.693769 22829 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:12.693914 22829 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:12.693984 22829 tablet_replica.cc:333] T 00000000000000000000000000000000 P 88a8986ac38e4e9f86c4692e0e2b3706: stopping tablet replica
I20260812 06:19:12.705938 22829 master.cc:584] Master@127.22.75.126:33311 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (4889 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:12.785617 22829 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.75.126:35229
I20260812 06:19:12.785970 22829 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:12.787842 23207 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:12.788012 23208 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:12.788033 23211 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:12.787881 22829 server_base.cc:1061] running on GCE node
I20260812 06:19:12.788286 22829 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:12.788318 22829 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:12.788337 22829 hybrid_clock.cc:648] HybridClock initialized: now 1786515552788337 us; error 0 us; skew 500 ppm
I20260812 06:19:12.789111 22829 webserver.cc:533] Webserver started at http://127.22.75.126:39537/ using document root <none> and password file <none>
I20260812 06:19:12.789261 22829 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:12.789305 22829 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:12.789376 22829 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:12.789763 22829 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/master-0-root/instance:
uuid: "c2e7231cbb4543999a0ed09fe4543272"
format_stamp: "Formatted at 2026-08-12 06:19:12 on dist-test-slave-42z9"
I20260812 06:19:12.791123 22829 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:12.791956 23221 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:12.792148 22829 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:12.792213 22829 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/master-0-root
uuid: "c2e7231cbb4543999a0ed09fe4543272"
format_stamp: "Formatted at 2026-08-12 06:19:12 on dist-test-slave-42z9"
I20260812 06:19:12.792280 22829 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:12.810597 22829 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:12.810940 22829 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:12.814853 22829 rpc_server.cc:307] RPC server started. Bound to: 127.22.75.126:35229
I20260812 06:19:12.815141 23317 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.75.126:35229 every 8 connection(s)
I20260812 06:19:12.815737 23318 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:12.817423 23318 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272: Bootstrap starting.
I20260812 06:19:12.818183 23318 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:12.819063 23318 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272: No bootstrap required, opened a new log
I20260812 06:19:12.819429 23318 raft_consensus.cc:359] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c2e7231cbb4543999a0ed09fe4543272" member_type: VOTER }
I20260812 06:19:12.819515 23318 raft_consensus.cc:385] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:12.819545 23318 raft_consensus.cc:740] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c2e7231cbb4543999a0ed09fe4543272, State: Initialized, Role: FOLLOWER
I20260812 06:19:12.819679 23318 consensus_queue.cc:260] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [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: "c2e7231cbb4543999a0ed09fe4543272" member_type: VOTER }
I20260812 06:19:12.819772 23318 raft_consensus.cc:399] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:12.819813 23318 raft_consensus.cc:493] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:12.819862 23318 raft_consensus.cc:3060] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:12.820530 23318 raft_consensus.cc:515] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c2e7231cbb4543999a0ed09fe4543272" member_type: VOTER }
I20260812 06:19:12.820652 23318 leader_election.cc:304] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [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: c2e7231cbb4543999a0ed09fe4543272; no voters: 
I20260812 06:19:12.820807 23318 leader_election.cc:290] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:12.820895 23322 raft_consensus.cc:2804] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:12.821084 23322 raft_consensus.cc:697] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [term 1 LEADER]: Becoming Leader. State: Replica: c2e7231cbb4543999a0ed09fe4543272, State: Running, Role: LEADER
I20260812 06:19:12.821204 23318 sys_catalog.cc:565] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:12.821237 23322 consensus_queue.cc:237] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [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: "c2e7231cbb4543999a0ed09fe4543272" member_type: VOTER }
I20260812 06:19:12.821664 23325 sys_catalog.cc:455] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "c2e7231cbb4543999a0ed09fe4543272" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c2e7231cbb4543999a0ed09fe4543272" member_type: VOTER } }
I20260812 06:19:12.821769 23325 sys_catalog.cc:458] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:12.821676 23326 sys_catalog.cc:455] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [sys.catalog]: SysCatalogTable state changed. Reason: New leader c2e7231cbb4543999a0ed09fe4543272. Latest consensus state: current_term: 1 leader_uuid: "c2e7231cbb4543999a0ed09fe4543272" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c2e7231cbb4543999a0ed09fe4543272" member_type: VOTER } }
I20260812 06:19:12.821981 23326 sys_catalog.cc:458] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:12.822389 23333 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:12.823063 23333 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:12.823230 22829 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:12.824642 23333 catalog_manager.cc:1383] Generated new cluster ID: 42930d988d364137860fe1880588149f
I20260812 06:19:12.824695 23333 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:12.837023 23333 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:12.837543 23333 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:12.846535 23333 catalog_manager.cc:6092] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272: Generated new TSK 0
I20260812 06:19:12.846668 23333 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:12.855291 22829 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:12.856863 23354 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:12.856974 23355 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:12.857110 23359 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:12.857120 22829 server_base.cc:1061] running on GCE node
I20260812 06:19:12.857314 22829 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:12.857352 22829 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:12.857370 22829 hybrid_clock.cc:648] HybridClock initialized: now 1786515552857370 us; error 0 us; skew 500 ppm
I20260812 06:19:12.858158 22829 webserver.cc:533] Webserver started at http://127.22.75.65:43587/ using document root <none> and password file <none>
I20260812 06:19:12.858302 22829 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:12.858348 22829 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:12.858419 22829 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:12.858757 22829 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/instance:
uuid: "369d9bce33b64cec9469e704c9d61978"
format_stamp: "Formatted at 2026-08-12 06:19:12 on dist-test-slave-42z9"
I20260812 06:19:12.860174 22829 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:12.861009 23366 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:12.861238 22829 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:12.861301 22829 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root
uuid: "369d9bce33b64cec9469e704c9d61978"
format_stamp: "Formatted at 2026-08-12 06:19:12 on dist-test-slave-42z9"
I20260812 06:19:12.861364 22829 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:12.881430 22829 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:12.881758 22829 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:12.882018 22829 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:12.882418 22829 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:12.882454 22829 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:12.882495 22829 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:12.882524 22829 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:12.886718 22829 rpc_server.cc:307] RPC server started. Bound to: 127.22.75.65:36053
I20260812 06:19:12.886765 23469 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.75.65:36053 every 8 connection(s)
I20260812 06:19:12.891112 23471 heartbeater.cc:344] Connected to a master server at 127.22.75.126:35229
I20260812 06:19:12.891214 23471 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:12.891396 23471 heartbeater.cc:507] Master 127.22.75.126:35229 requested a full tablet report, sending...
I20260812 06:19:12.892024 23257 ts_manager.cc:194] Registered new tserver with Master: 369d9bce33b64cec9469e704c9d61978 (127.22.75.65:36053)
I20260812 06:19:12.892611 22829 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.005500714s
I20260812 06:19:12.892705 23257 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41070
I20260812 06:19:12.898669 23257 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41086:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:12.906309 23414 tablet_service.cc:1511] Processing CreateTablet for tablet 8f555042cd0f4e289d9e25d1486d4b11 (DEFAULT_TABLE table=heavy-update-compaction-test [id=eb75ba62645d498f8f67fa19ec590bb3]), partition=
I20260812 06:19:12.906548 23414 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8f555042cd0f4e289d9e25d1486d4b11. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:12.908324 23497 tablet_bootstrap.cc:492] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Bootstrap starting.
I20260812 06:19:12.909322 23497 tablet_bootstrap.cc:654] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:12.910272 23497 tablet_bootstrap.cc:492] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: No bootstrap required, opened a new log
I20260812 06:19:12.910342 23497 ts_tablet_manager.cc:1403] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:19:12.910703 23497 raft_consensus.cc:359] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "369d9bce33b64cec9469e704c9d61978" member_type: VOTER last_known_addr { host: "127.22.75.65" port: 36053 } }
I20260812 06:19:12.910784 23497 raft_consensus.cc:385] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:12.910810 23497 raft_consensus.cc:740] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 369d9bce33b64cec9469e704c9d61978, State: Initialized, Role: FOLLOWER
I20260812 06:19:12.910904 23497 consensus_queue.cc:260] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978 [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: "369d9bce33b64cec9469e704c9d61978" member_type: VOTER last_known_addr { host: "127.22.75.65" port: 36053 } }
I20260812 06:19:12.910964 23497 raft_consensus.cc:399] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:12.910990 23497 raft_consensus.cc:493] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:12.911021 23497 raft_consensus.cc:3060] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:12.911737 23497 raft_consensus.cc:515] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "369d9bce33b64cec9469e704c9d61978" member_type: VOTER last_known_addr { host: "127.22.75.65" port: 36053 } }
I20260812 06:19:12.911873 23497 leader_election.cc:304] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978 [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: 369d9bce33b64cec9469e704c9d61978; no voters: 
I20260812 06:19:12.912062 23497 leader_election.cc:290] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:12.912148 23500 raft_consensus.cc:2804] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:12.912318 23500 raft_consensus.cc:697] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978 [term 1 LEADER]: Becoming Leader. State: Replica: 369d9bce33b64cec9469e704c9d61978, State: Running, Role: LEADER
I20260812 06:19:12.912420 23471 heartbeater.cc:499] Master 127.22.75.126:35229 was elected leader, sending a full tablet report...
I20260812 06:19:12.912477 23500 consensus_queue.cc:237] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978 [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: "369d9bce33b64cec9469e704c9d61978" member_type: VOTER last_known_addr { host: "127.22.75.65" port: 36053 } }
I20260812 06:19:12.912633 23497 ts_tablet_manager.cc:1434] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:12.913671 23257 catalog_manager.cc:5719] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978 reported cstate change: term changed from 0 to 1, leader changed from <none> to 369d9bce33b64cec9469e704c9d61978 (127.22.75.65). New cstate: current_term: 1 leader_uuid: "369d9bce33b64cec9469e704c9d61978" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "369d9bce33b64cec9469e704c9d61978" member_type: VOTER last_known_addr { host: "127.22.75.65" port: 36053 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:12.965938 22829 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.014s	sys 0.007s
I20260812 06:19:13.137633 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushMRSOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=23.023690
I20260812 06:19:13.295291 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushMRSOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.157s	user 0.104s	sys 0.052s Metrics: {"bytes_written":13907425,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":154,"dirs.run_wall_time_us":924,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37888,"lbm_writes_lt_1ms":896,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":14592,"update_count":1695}
I20260812 06:19:13.295993 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling LogGCOp(8f555042cd0f4e289d9e25d1486d4b11): free 20743880 bytes of WAL
I20260812 06:19:13.296216 23374 log_reader.cc:385] T 8f555042cd0f4e289d9e25d1486d4b11: removed 2 log segments from log reader
I20260812 06:19:13.296271 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000001 (ops 1-6)
I20260812 06:19:13.296365 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000002 (ops 7-11)
I20260812 06:19:13.300417 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: LogGCOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:13.300801 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:13.311239 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.010s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3241140,"delete_count":0,"lbm_write_time_us":2939,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:19:13.311625 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling UndoDeltaBlockGCOp(8f555042cd0f4e289d9e25d1486d4b11): 20513813 bytes on disk
I20260812 06:19:13.312011 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: UndoDeltaBlockGCOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:13.312402 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:13.320582 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.008s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":3013,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:19:13.320935 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:13.491851 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.171s	user 0.117s	sys 0.051s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815765,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":411,"lbm_read_time_us":12370,"lbm_reads_lt_1ms":569,"lbm_write_time_us":25923,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":314,"threads_started":5,"update_count":2500}
I20260812 06:19:13.492355 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=14.095187
I20260812 06:19:13.550031 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.058s	user 0.014s	sys 0.042s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19508,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.550542 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:13.560577 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3833,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.560984 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:13.731752 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.171s	user 0.105s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":735,"lbm_read_time_us":11237,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26138,"lbm_writes_lt_1ms":543,"mutex_wait_us":63,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:19:13.732309 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=14.095187
I20260812 06:19:13.774463 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.042s	user 0.026s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16640,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.774935 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:13.794973 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.020s	user 0.007s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4195,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.795516 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:13.962558 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.167s	user 0.102s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":109,"lbm_read_time_us":12697,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25008,"lbm_writes_lt_1ms":543,"mutex_wait_us":17,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:19:13.963063 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=14.095187
I20260812 06:19:14.006250 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.043s	user 0.032s	sys 0.007s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":16926,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.006733 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:14.016686 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3645,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.017271 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:14.197760 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.180s	user 0.111s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":648,"lbm_read_time_us":10384,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27557,"lbm_writes_lt_1ms":543,"mutex_wait_us":274,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2500}
I20260812 06:19:14.198251 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=14.095187
I20260812 06:19:14.244848 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.046s	user 0.016s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17158,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.245339 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:14.256628 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4011,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.257108 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:14.409062 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.152s	user 0.104s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":167,"lbm_read_time_us":8721,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29221,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2500}
I20260812 06:19:14.409660 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=14.095187
I20260812 06:19:14.458997 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.049s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":20493,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.459475 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:14.469736 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3751,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.470382 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushMRSOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:14.495975 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushMRSOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.025s	user 0.022s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":1272,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1244,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:14.496618 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling LogGCOp(8f555042cd0f4e289d9e25d1486d4b11): free 124257242 bytes of WAL
I20260812 06:19:14.496819 23374 log_reader.cc:385] T 8f555042cd0f4e289d9e25d1486d4b11: removed 12 log segments from log reader
I20260812 06:19:14.496867 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000003 (ops 12-16)
I20260812 06:19:14.496909 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000004 (ops 17-21)
I20260812 06:19:14.496938 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000005 (ops 22-26)
I20260812 06:19:14.496966 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000006 (ops 27-31)
I20260812 06:19:14.496999 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000007 (ops 32-36)
I20260812 06:19:14.497038 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000008 (ops 37-41)
I20260812 06:19:14.497066 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000009 (ops 42-46)
I20260812 06:19:14.497094 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000010 (ops 47-50)
I20260812 06:19:14.497124 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000011 (ops 51-55)
I20260812 06:19:14.497154 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000012 (ops 56-60)
I20260812 06:19:14.497184 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000013 (ops 61-65)
I20260812 06:19:14.497210 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000014 (ops 66-70)
I20260812 06:19:14.523075 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: LogGCOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:14.523449 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=3.181125
I20260812 06:19:14.536834 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.013s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":3930,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:14.537259 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:14.554471 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.017s	user 0.009s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3490,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:14.554957 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:14.776381 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.221s	user 0.132s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020736,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":457,"lbm_read_time_us":15397,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35460,"lbm_writes_lt_1ms":743,"mutex_wait_us":43,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4352,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:19:14.776993 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling UndoDeltaBlockGCOp(8f555042cd0f4e289d9e25d1486d4b11): 473 bytes on disk
I20260812 06:19:14.777423 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: UndoDeltaBlockGCOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:19:14.778015 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=15.087375
I20260812 06:19:14.832420 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.054s	user 0.012s	sys 0.024s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":16411,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:14.833156 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=3.181125
I20260812 06:19:14.849256 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4964166,"delete_count":0,"lbm_write_time_us":6504,"lbm_writes_lt_1ms":124,"reinsert_count":0,"update_count":605}
I20260812 06:19:14.849702 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.196750
I20260812 06:19:14.858803 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3221,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:19:14.859340 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:15.051157 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.192s	user 0.132s	sys 0.059s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918184,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":755,"lbm_read_time_us":12120,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30129,"lbm_writes_lt_1ms":643,"mutex_wait_us":153,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:15.051680 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=14.095187
I20260812 06:19:15.100759 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.049s	user 0.036s	sys 0.007s Metrics: {"bytes_written":16491951,"delete_count":0,"lbm_write_time_us":20610,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2010}
I20260812 06:19:15.101294 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=3.181125
I20260812 06:19:15.112581 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4430855,"delete_count":0,"lbm_write_time_us":4330,"lbm_writes_lt_1ms":111,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":540}
I20260812 06:19:15.113039 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:15.126577 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4957,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:15.127056 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:15.319875 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.193s	user 0.141s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":142,"lbm_read_time_us":13770,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31316,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":3000}
I20260812 06:19:15.320428 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=14.095187
I20260812 06:19:15.376485 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.055s	user 0.023s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19196,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.376986 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:15.387193 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3870,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.387868 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:15.544265 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.156s	user 0.123s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":313,"lbm_read_time_us":11054,"lbm_reads_lt_1ms":572,"lbm_write_time_us":23972,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:19:15.544916 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=14.095187
I20260812 06:19:15.603292 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.058s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20185,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.603796 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:15.614573 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3880,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.614976 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:15.779623 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.164s	user 0.110s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1152,"lbm_read_time_us":12296,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26107,"lbm_writes_lt_1ms":543,"mutex_wait_us":352,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:19:15.780112 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=14.095187
I20260812 06:19:15.834033 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.054s	user 0.034s	sys 0.018s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20096,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.834583 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:15.844625 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3852,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.845039 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushMRSOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:15.884063 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushMRSOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.039s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":167,"dirs.run_wall_time_us":1106,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1752,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:15.884721 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling LogGCOp(8f555042cd0f4e289d9e25d1486d4b11): free 121006451 bytes of WAL
I20260812 06:19:15.884935 23374 log_reader.cc:385] T 8f555042cd0f4e289d9e25d1486d4b11: removed 12 log segments from log reader
I20260812 06:19:15.884979 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000015 (ops 71-75)
I20260812 06:19:15.885016 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000016 (ops 76-80)
I20260812 06:19:15.885048 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000017 (ops 81-85)
I20260812 06:19:15.885079 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000018 (ops 86-90)
I20260812 06:19:15.885111 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000019 (ops 91-95)
I20260812 06:19:15.885144 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000020 (ops 96-100)
I20260812 06:19:15.885177 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000021 (ops 101-104)
I20260812 06:19:15.885210 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000022 (ops 105-109)
I20260812 06:19:15.885241 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000023 (ops 110-114)
I20260812 06:19:15.885272 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000024 (ops 115-119)
I20260812 06:19:15.885304 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000025 (ops 120-124)
I20260812 06:19:15.885335 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000026 (ops 125-129)
I20260812 06:19:15.904934 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: LogGCOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.020s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:19:15.905285 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling UndoDeltaBlockGCOp(8f555042cd0f4e289d9e25d1486d4b11): 462 bytes on disk
I20260812 06:19:15.905712 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: UndoDeltaBlockGCOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:19:15.906185 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:15.930332 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.024s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4019,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.930737 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:15.940371 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.009s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3592,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.940810 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:16.158339 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.217s	user 0.157s	sys 0.059s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020746,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":534,"lbm_read_time_us":12436,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39678,"lbm_writes_lt_1ms":743,"mutex_wait_us":273,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10880,"thread_start_us":69,"threads_started":1,"update_count":3500}
I20260812 06:19:16.160128 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=18.063937
I20260812 06:19:16.212392 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.052s	user 0.021s	sys 0.028s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":22878,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:16.212812 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:16.224109 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4228,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.224613 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:16.386531 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.162s	user 0.125s	sys 0.036s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":238,"lbm_read_time_us":10798,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31909,"lbm_writes_lt_1ms":643,"mutex_wait_us":29,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":3000}
I20260812 06:19:16.387167 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=14.095187
I20260812 06:19:16.426028 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.039s	user 0.027s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":16783,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.426565 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:16.437186 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3490,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.437904 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:16.582988 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.145s	user 0.107s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":188,"lbm_read_time_us":9070,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27559,"lbm_writes_lt_1ms":543,"mutex_wait_us":72,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:19:16.583652 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=12.110812
I20260812 06:19:16.620622 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.037s	user 0.030s	sys 0.004s Metrics: {"bytes_written":13743340,"delete_count":0,"lbm_write_time_us":15366,"lbm_writes_lt_1ms":338,"reinsert_count":0,"update_count":1675}
I20260812 06:19:16.621206 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.196750
I20260812 06:19:16.640954 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.020s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2666779,"delete_count":0,"lbm_write_time_us":3210,"lbm_writes_lt_1ms":68,"reinsert_count":0,"update_count":325}
I20260812 06:19:16.641390 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:16.656267 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.015s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5257,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.656875 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:16.816329 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.159s	user 0.117s	sys 0.041s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815772,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":521,"lbm_read_time_us":10728,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27027,"lbm_writes_lt_1ms":543,"mutex_wait_us":267,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:19:16.816885 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=14.095187
I20260812 06:19:16.872373 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.055s	user 0.027s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22764,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.872910 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:16.883201 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3667,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.883767 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:17.039152 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.155s	user 0.088s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":111,"lbm_read_time_us":11468,"lbm_reads_lt_1ms":572,"lbm_write_time_us":23027,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:19:17.041847 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=14.095187
I20260812 06:19:17.096272 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.054s	user 0.029s	sys 0.022s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19250,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.096971 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:17.111901 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5716,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.112653 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushMRSOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:17.146418 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushMRSOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.034s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":172,"dirs.run_wall_time_us":1063,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1979,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28,"spinlock_wait_cycles":6400}
I20260812 06:19:17.147234 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling LogGCOp(8f555042cd0f4e289d9e25d1486d4b11): free 112239561 bytes of WAL
I20260812 06:19:17.147456 23374 log_reader.cc:385] T 8f555042cd0f4e289d9e25d1486d4b11: removed 11 log segments from log reader
I20260812 06:19:17.147512 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000027 (ops 130-134)
I20260812 06:19:17.147552 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000028 (ops 135-139)
I20260812 06:19:17.147585 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000029 (ops 140-144)
I20260812 06:19:17.147616 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000030 (ops 145-148)
I20260812 06:19:17.147647 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000031 (ops 149-153)
I20260812 06:19:17.147679 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000032 (ops 154-158)
I20260812 06:19:17.147710 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000033 (ops 159-163)
I20260812 06:19:17.147740 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000034 (ops 164-168)
I20260812 06:19:17.147775 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000035 (ops 169-173)
I20260812 06:19:17.147806 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000036 (ops 174-178)
I20260812 06:19:17.147836 23374 log.cc:1079] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: Deleting log segment in path: /tmp/dist-test-taskv12yPj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515547876021-22829-0/minicluster-data/ts-0-root/wals/8f555042cd0f4e289d9e25d1486d4b11/wal-000000037 (ops 179-183)
I20260812 06:19:17.167775 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: LogGCOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.020s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:19:17.168216 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:17.191099 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.022s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5255,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.191579 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:17.201709 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3839,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.202368 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:17.419028 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.216s	user 0.153s	sys 0.054s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020748,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":120,"lbm_read_time_us":13807,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35439,"lbm_writes_lt_1ms":743,"mutex_wait_us":23,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":38272,"thread_start_us":72,"threads_started":1,"update_count":3500}
I20260812 06:19:17.419595 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling UndoDeltaBlockGCOp(8f555042cd0f4e289d9e25d1486d4b11): 447 bytes on disk
I20260812 06:19:17.420011 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: UndoDeltaBlockGCOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:19:17.420610 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=18.063937
I20260812 06:19:17.464781 22829 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.499s	user 1.661s	sys 0.133s
I20260812 06:19:17.482877 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.062s	user 0.044s	sys 0.017s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26400,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:17.483525 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=2.188937
I20260812 06:19:17.494540 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: FlushDeltaMemStoresOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.011s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4155,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.494746 22829 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.030s	user 0.002s	sys 0.000s
I20260812 06:19:17.494967 23472 maintenance_manager.cc:419] P 369d9bce33b64cec9469e704c9d61978: Scheduling MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11): perf score=1.000000
I20260812 06:19:17.495184 22829 tablet_server.cc:179] TabletServer@127.22.75.65:0 shutting down...
I20260812 06:19:17.630472 23374 maintenance_manager.cc:643] P 369d9bce33b64cec9469e704c9d61978: MajorDeltaCompactionOp(8f555042cd0f4e289d9e25d1486d4b11) complete. Timing: real 0.135s	user 0.105s	sys 0.030s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4303385,"cfile_cache_miss":602,"cfile_cache_miss_bytes":24614714,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":457,"lbm_read_time_us":8188,"lbm_reads_lt_1ms":618,"lbm_write_time_us":24749,"lbm_writes_lt_1ms":643,"mutex_wait_us":90,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:17.631072 22829 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:17.631296 22829 tablet_replica.cc:333] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978: stopping tablet replica
I20260812 06:19:17.631434 22829 raft_consensus.cc:2243] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:17.631592 22829 raft_consensus.cc:2272] T 8f555042cd0f4e289d9e25d1486d4b11 P 369d9bce33b64cec9469e704c9d61978 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:17.645093 22829 tablet_server.cc:196] TabletServer@127.22.75.65:0 shutdown complete.
I20260812 06:19:17.681807 22829 master.cc:562] Master@127.22.75.126:35229 shutting down...
I20260812 06:19:17.684804 22829 raft_consensus.cc:2243] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:17.684974 22829 raft_consensus.cc:2272] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:17.685038 22829 tablet_replica.cc:333] T 00000000000000000000000000000000 P c2e7231cbb4543999a0ed09fe4543272: stopping tablet replica
I20260812 06:19:17.697124 22829 master.cc:584] Master@127.22.75.126:35229 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4992 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9882 ms total)

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