[==========] 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:14.706496  6760 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.6.154.62:45359
I20260812 06:19:14.707602  6760 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:14.708249  6760 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:14.715294  6767 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:14.715449  6760 server_base.cc:1061] running on GCE node
W20260812 06:19:14.715340  6771 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:14.715674  6775 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:14.716240  6760 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:14.716372  6760 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:14.716430  6760 hybrid_clock.cc:648] HybridClock initialized: now 1786515554716422 us; error 0 us; skew 500 ppm
I20260812 06:19:14.718537  6760 webserver.cc:533] Webserver started at http://127.6.154.62:45895/ using document root <none> and password file <none>
I20260812 06:19:14.719170  6760 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:14.719256  6760 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:14.719547  6760 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:14.721285  6760 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/master-0-root/instance:
uuid: "180426182ba244f186f355a626b991d2"
format_stamp: "Formatted at 2026-08-12 06:19:14 on dist-test-slave-3kk6"
I20260812 06:19:14.725112  6760 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:14.727335  6789 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:14.728421  6760 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:14.728575  6760 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/master-0-root
uuid: "180426182ba244f186f355a626b991d2"
format_stamp: "Formatted at 2026-08-12 06:19:14 on dist-test-slave-3kk6"
I20260812 06:19:14.728691  6760 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-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:14.743968  6760 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:14.744733  6760 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:14.744963  6760 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:14.753429  6760 rpc_server.cc:307] RPC server started. Bound to: 127.6.154.62:45359
I20260812 06:19:14.753448  6872 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.154.62:45359 every 8 connection(s)
I20260812 06:19:14.755851  6875 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:14.761373  6875 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2: Bootstrap starting.
I20260812 06:19:14.763799  6875 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:14.764721  6875 log.cc:826] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:14.766502  6875 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2: No bootstrap required, opened a new log
I20260812 06:19:14.769414  6875 raft_consensus.cc:359] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "180426182ba244f186f355a626b991d2" member_type: VOTER }
I20260812 06:19:14.769583  6875 raft_consensus.cc:385] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:14.769625  6875 raft_consensus.cc:740] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 180426182ba244f186f355a626b991d2, State: Initialized, Role: FOLLOWER
I20260812 06:19:14.770169  6875 consensus_queue.cc:260] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [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: "180426182ba244f186f355a626b991d2" member_type: VOTER }
I20260812 06:19:14.770305  6875 raft_consensus.cc:399] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:14.770346  6875 raft_consensus.cc:493] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:14.770430  6875 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:14.771226  6875 raft_consensus.cc:515] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "180426182ba244f186f355a626b991d2" member_type: VOTER }
I20260812 06:19:14.771625  6875 leader_election.cc:304] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [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: 180426182ba244f186f355a626b991d2; no voters: 
I20260812 06:19:14.771951  6875 leader_election.cc:290] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:14.772130  6880 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:14.772420  6880 raft_consensus.cc:697] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [term 1 LEADER]: Becoming Leader. State: Replica: 180426182ba244f186f355a626b991d2, State: Running, Role: LEADER
I20260812 06:19:14.772837  6880 consensus_queue.cc:237] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [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: "180426182ba244f186f355a626b991d2" member_type: VOTER }
I20260812 06:19:14.773039  6875 sys_catalog.cc:565] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:14.774830  6882 sys_catalog.cc:455] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 180426182ba244f186f355a626b991d2. Latest consensus state: current_term: 1 leader_uuid: "180426182ba244f186f355a626b991d2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "180426182ba244f186f355a626b991d2" member_type: VOTER } }
I20260812 06:19:14.774875  6881 sys_catalog.cc:455] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "180426182ba244f186f355a626b991d2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "180426182ba244f186f355a626b991d2" member_type: VOTER } }
I20260812 06:19:14.774960  6882 sys_catalog.cc:458] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:14.774982  6881 sys_catalog.cc:458] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:14.775694  6760 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:19:14.777973  6904 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:14.778069  6904 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:14.778164  6899 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:14.779109  6899 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:14.783866  6899 catalog_manager.cc:1383] Generated new cluster ID: 100746e9d8184e61b9e96388247516dd
I20260812 06:19:14.783953  6899 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:14.790246  6899 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:14.791260  6899 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:14.802868  6899 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2: Generated new TSK 0
I20260812 06:19:14.803622  6899 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:14.808377  6760 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:14.811439  6913 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:14.811476  6911 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:14.811584  6915 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:14.811960  6760 server_base.cc:1061] running on GCE node
I20260812 06:19:14.812167  6760 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:14.812208  6760 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:14.812247  6760 hybrid_clock.cc:648] HybridClock initialized: now 1786515554812245 us; error 0 us; skew 500 ppm
I20260812 06:19:14.813328  6760 webserver.cc:533] Webserver started at http://127.6.154.1:36309/ using document root <none> and password file <none>
I20260812 06:19:14.813530  6760 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:14.813593  6760 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:14.813699  6760 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:14.814188  6760 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/instance:
uuid: "c54694640a8d4c3db49b18a89f9537df"
format_stamp: "Formatted at 2026-08-12 06:19:14 on dist-test-slave-3kk6"
I20260812 06:19:14.815909  6760 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:14.817065  6927 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:14.817332  6760 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:14.817410  6760 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root
uuid: "c54694640a8d4c3db49b18a89f9537df"
format_stamp: "Formatted at 2026-08-12 06:19:14 on dist-test-slave-3kk6"
I20260812 06:19:14.817516  6760 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-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:14.828872  6760 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:14.829380  6760 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:14.829941  6760 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:14.830925  6760 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:14.830989  6760 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:14.831065  6760 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:14.831110  6760 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:14.838455  6760 rpc_server.cc:307] RPC server started. Bound to: 127.6.154.1:33079
I20260812 06:19:14.838523  7030 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.154.1:33079 every 8 connection(s)
I20260812 06:19:14.853304  7032 heartbeater.cc:344] Connected to a master server at 127.6.154.62:45359
I20260812 06:19:14.853600  7032 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:14.854123  7032 heartbeater.cc:507] Master 127.6.154.62:45359 requested a full tablet report, sending...
I20260812 06:19:14.855729  6812 ts_manager.cc:194] Registered new tserver with Master: c54694640a8d4c3db49b18a89f9537df (127.6.154.1:33079)
I20260812 06:19:14.855994  6760 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01679402s
I20260812 06:19:14.857064  6812 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57536
I20260812 06:19:14.866422  6812 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57544:
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:14.881351  6976 tablet_service.cc:1511] Processing CreateTablet for tablet 79b86705eb6843229121212619a51e22 (DEFAULT_TABLE table=heavy-update-compaction-test [id=817f1fccbd8e4a92868e7212cda8db94]), partition=
I20260812 06:19:14.881887  6976 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 79b86705eb6843229121212619a51e22. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:14.884807  7048 tablet_bootstrap.cc:492] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Bootstrap starting.
I20260812 06:19:14.885710  7048 tablet_bootstrap.cc:654] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:14.887079  7048 tablet_bootstrap.cc:492] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: No bootstrap required, opened a new log
I20260812 06:19:14.887188  7048 ts_tablet_manager.cc:1403] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:14.887704  7048 raft_consensus.cc:359] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c54694640a8d4c3db49b18a89f9537df" member_type: VOTER last_known_addr { host: "127.6.154.1" port: 33079 } }
I20260812 06:19:14.887836  7048 raft_consensus.cc:385] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:14.887871  7048 raft_consensus.cc:740] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c54694640a8d4c3db49b18a89f9537df, State: Initialized, Role: FOLLOWER
I20260812 06:19:14.888011  7048 consensus_queue.cc:260] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df [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: "c54694640a8d4c3db49b18a89f9537df" member_type: VOTER last_known_addr { host: "127.6.154.1" port: 33079 } }
I20260812 06:19:14.888110  7048 raft_consensus.cc:399] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:14.888146  7048 raft_consensus.cc:493] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:14.888196  7048 raft_consensus.cc:3060] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:14.889148  7048 raft_consensus.cc:515] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c54694640a8d4c3db49b18a89f9537df" member_type: VOTER last_known_addr { host: "127.6.154.1" port: 33079 } }
I20260812 06:19:14.889310  7048 leader_election.cc:304] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df [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: c54694640a8d4c3db49b18a89f9537df; no voters: 
I20260812 06:19:14.889530  7048 leader_election.cc:290] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:14.889685  7050 raft_consensus.cc:2804] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:14.889842  7048 ts_tablet_manager.cc:1434] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:14.890305  7032 heartbeater.cc:499] Master 127.6.154.62:45359 was elected leader, sending a full tablet report...
I20260812 06:19:14.889997  7050 raft_consensus.cc:697] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df [term 1 LEADER]: Becoming Leader. State: Replica: c54694640a8d4c3db49b18a89f9537df, State: Running, Role: LEADER
I20260812 06:19:14.890838  7050 consensus_queue.cc:237] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df [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: "c54694640a8d4c3db49b18a89f9537df" member_type: VOTER last_known_addr { host: "127.6.154.1" port: 33079 } }
I20260812 06:19:14.893828  6812 catalog_manager.cc:5719] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df reported cstate change: term changed from 0 to 1, leader changed from <none> to c54694640a8d4c3db49b18a89f9537df (127.6.154.1). New cstate: current_term: 1 leader_uuid: "c54694640a8d4c3db49b18a89f9537df" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c54694640a8d4c3db49b18a89f9537df" member_type: VOTER last_known_addr { host: "127.6.154.1" port: 33079 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:14.964545  6760 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.018s	sys 0.010s
I20260812 06:19:15.089784  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushMRSOp(79b86705eb6843229121212619a51e22): perf score=15.086190
I20260812 06:19:15.236999  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushMRSOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.147s	user 0.099s	sys 0.044s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":238,"delete_count":0,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":920,"drs_written":1,"lbm_read_time_us":103,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38160,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":115,"threads_started":1,"update_count":1450}
I20260812 06:19:15.238171  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling UndoDeltaBlockGCOp(79b86705eb6843229121212619a51e22): 12719217 bytes on disk
I20260812 06:19:15.238782  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: UndoDeltaBlockGCOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:15.239431  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:15.251035  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.011s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1230906,"delete_count":0,"lbm_write_time_us":1331,"lbm_writes_lt_1ms":33,"reinsert_count":0,"update_count":150}
I20260812 06:19:15.251591  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling LogGCOp(79b86705eb6843229121212619a51e22): free 20743880 bytes of WAL
I20260812 06:19:15.251986  6937 log_reader.cc:385] T 79b86705eb6843229121212619a51e22: removed 2 log segments from log reader
I20260812 06:19:15.252104  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000001 (ops 1-6)
I20260812 06:19:15.252215  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000002 (ops 7-11)
I20260812 06:19:15.258260  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: LogGCOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.006s	user 0.002s	sys 0.003s Metrics: {}
I20260812 06:19:15.258598  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=1.196750
I20260812 06:19:15.270197  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":4092,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:19:15.270888  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:15.412569  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.141s	user 0.104s	sys 0.032s Metrics: {"cfile_cache_miss":423,"cfile_cache_miss_bytes":20262061,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":709,"lbm_read_time_us":9539,"lbm_reads_lt_1ms":459,"lbm_write_time_us":26960,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"thread_start_us":372,"threads_started":5,"update_count":1950}
I20260812 06:19:15.413172  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=10.126437
I20260812 06:19:15.460928  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.048s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15111,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:15.461541  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:15.477766  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5913,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.478475  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:15.606429  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.128s	user 0.098s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":602,"lbm_read_time_us":8664,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27185,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":2000}
I20260812 06:19:15.607122  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=10.126437
I20260812 06:19:15.662408  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.055s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14904,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:15.663028  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:15.674294  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4362,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.674961  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:15.833935  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.159s	user 0.111s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":235,"lbm_read_time_us":11765,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27168,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:19:15.834707  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=10.126437
I20260812 06:19:15.880847  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.046s	user 0.022s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17488,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:15.881313  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:15.893514  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4160,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.894202  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:16.026520  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.132s	user 0.099s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":984,"lbm_read_time_us":10242,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26167,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:19:16.027278  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=10.126437
I20260812 06:19:16.068720  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.041s	user 0.031s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17671,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.069288  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:16.080814  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4424,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.081585  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:16.206557  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.125s	user 0.107s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":370,"lbm_read_time_us":9794,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25648,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2000}
I20260812 06:19:16.207247  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=10.126437
I20260812 06:19:16.257771  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.050s	user 0.023s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20516,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.258244  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:16.269104  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4076,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.269832  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:16.408449  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.138s	user 0.096s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":337,"lbm_read_time_us":10683,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30887,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2000}
I20260812 06:19:16.409232  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=10.126437
I20260812 06:19:16.466357  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.057s	user 0.020s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17151,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.467151  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:16.484814  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6715,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.485416  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:16.639818  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.154s	user 0.120s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":936,"lbm_read_time_us":11643,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25230,"lbm_writes_lt_1ms":443,"mutex_wait_us":361,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2000}
I20260812 06:19:16.640583  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=10.126437
I20260812 06:19:16.675845  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.035s	user 0.014s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15060,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.676446  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushMRSOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:16.715802  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushMRSOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.039s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1351,"drs_written":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2068,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:16.716832  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=3.181125
I20260812 06:19:16.728811  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4564,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:16.729383  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling LogGCOp(79b86705eb6843229121212619a51e22): free 121006442 bytes of WAL
I20260812 06:19:16.729601  6937 log_reader.cc:385] T 79b86705eb6843229121212619a51e22: removed 12 log segments from log reader
I20260812 06:19:16.729651  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000003 (ops 12-16)
I20260812 06:19:16.729691  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000004 (ops 17-21)
I20260812 06:19:16.729727  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000005 (ops 22-26)
I20260812 06:19:16.729751  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000006 (ops 27-31)
I20260812 06:19:16.729773  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000007 (ops 32-36)
I20260812 06:19:16.729802  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000008 (ops 37-41)
I20260812 06:19:16.729835  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000009 (ops 42-46)
I20260812 06:19:16.729871  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000010 (ops 47-50)
I20260812 06:19:16.729902  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000011 (ops 51-55)
I20260812 06:19:16.729933  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000012 (ops 56-60)
I20260812 06:19:16.729961  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000013 (ops 61-65)
I20260812 06:19:16.729990  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000014 (ops 66-70)
I20260812 06:19:16.763605  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: LogGCOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.034s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:19:16.764039  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling UndoDeltaBlockGCOp(79b86705eb6843229121212619a51e22): 483 bytes on disk
I20260812 06:19:16.764514  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: UndoDeltaBlockGCOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:19:16.765039  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:16.795917  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.031s	user 0.005s	sys 0.014s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4336,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:16.796537  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling LogGCOp(79b86705eb6843229121212619a51e22): free 11564875 bytes of WAL
I20260812 06:19:16.796789  6937 log_reader.cc:385] T 79b86705eb6843229121212619a51e22: removed 1 log segments from log reader
I20260812 06:19:16.796839  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000015 (ops 71-74)
I20260812 06:19:16.799374  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: LogGCOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:16.799759  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:16.810806  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.011s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4272,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.811271  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:17.026453  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.215s	user 0.147s	sys 0.068s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":393,"lbm_read_time_us":15866,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40499,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14720,"thread_start_us":93,"threads_started":1,"update_count":3000}
I20260812 06:19:17.027069  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=10.126437
I20260812 06:19:17.063421  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.036s	user 0.016s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16076,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.064009  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:17.079996  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5881,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.080770  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:17.240948  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.160s	user 0.098s	sys 0.053s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":225,"lbm_read_time_us":10794,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25365,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":88832,"update_count":2000}
I20260812 06:19:17.241796  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=10.126437
I20260812 06:19:17.291620  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.050s	user 0.009s	sys 0.031s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18310,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.292277  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:17.303678  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4098,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.304248  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:17.431737  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.127s	user 0.087s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":639,"lbm_read_time_us":10020,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24087,"lbm_writes_lt_1ms":443,"mutex_wait_us":70,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20864,"update_count":2000}
I20260812 06:19:17.432642  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=10.126437
I20260812 06:19:17.468300  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.035s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15476,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.468885  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:17.485244  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.016s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6031,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.485996  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:17.605111  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.119s	user 0.090s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1119,"lbm_read_time_us":8520,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23727,"lbm_writes_lt_1ms":443,"mutex_wait_us":341,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20864,"update_count":2000}
I20260812 06:19:17.605837  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=10.126437
I20260812 06:19:17.662289  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.056s	user 0.032s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17908,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.663017  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:17.674377  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4393,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.674945  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:17.821070  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.146s	user 0.116s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":900,"lbm_read_time_us":11245,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23459,"lbm_writes_lt_1ms":443,"mutex_wait_us":384,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:17.821779  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=10.126437
I20260812 06:19:17.860109  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.038s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14759,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.860641  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:17.877203  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6038,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.877925  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:18.010958  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.133s	user 0.095s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":557,"lbm_read_time_us":9242,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26121,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.011814  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=10.126437
I20260812 06:19:18.054450  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.042s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19987,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:18.055078  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:18.069008  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.014s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5163,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.069679  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:18.211851  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.142s	user 0.109s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":772,"lbm_read_time_us":10737,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28037,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":89728,"update_count":2000}
I20260812 06:19:18.212705  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=10.126437
I20260812 06:19:18.263859  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.051s	user 0.031s	sys 0.019s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17846,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:18.264528  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:18.275840  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4274,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.276362  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushMRSOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:18.315296  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushMRSOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.039s	user 0.030s	sys 0.004s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1367,"drs_written":1,"lbm_read_time_us":52,"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:18.316057  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling LogGCOp(79b86705eb6843229121212619a51e22): free 112692318 bytes of WAL
I20260812 06:19:18.316294  6937 log_reader.cc:385] T 79b86705eb6843229121212619a51e22: removed 11 log segments from log reader
I20260812 06:19:18.316345  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000016 (ops 75-79)
I20260812 06:19:18.316395  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000017 (ops 80-84)
I20260812 06:19:18.316444  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000018 (ops 85-89)
I20260812 06:19:18.316476  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000019 (ops 90-94)
I20260812 06:19:18.316522  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000020 (ops 95-99)
I20260812 06:19:18.316571  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000021 (ops 100-104)
I20260812 06:19:18.316612  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000022 (ops 105-109)
I20260812 06:19:18.316654  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000023 (ops 110-114)
I20260812 06:19:18.316691  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000024 (ops 115-119)
I20260812 06:19:18.316730  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000025 (ops 120-124)
I20260812 06:19:18.316773  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000026 (ops 125-129)
I20260812 06:19:18.342825  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: LogGCOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:18.343271  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling UndoDeltaBlockGCOp(79b86705eb6843229121212619a51e22): 472 bytes on disk
I20260812 06:19:18.343839  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: UndoDeltaBlockGCOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4}
I20260812 06:19:18.344429  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=3.181125
I20260812 06:19:18.360535  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.016s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4532,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:18.361023  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:18.370966  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3685,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:18.371479  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:18.579104  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.207s	user 0.133s	sys 0.071s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":372,"lbm_read_time_us":14893,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33676,"lbm_writes_lt_1ms":643,"mutex_wait_us":75,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20608,"thread_start_us":99,"threads_started":1,"update_count":3000}
I20260812 06:19:18.579878  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=14.095187
I20260812 06:19:18.637599  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.057s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25723,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.638302  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:18.659902  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.021s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5733,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.660456  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:18.839856  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.179s	user 0.131s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":164,"lbm_read_time_us":11468,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31353,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:19:18.840634  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=14.095187
I20260812 06:19:18.899001  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.058s	user 0.042s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21695,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.899770  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=3.181125
I20260812 06:19:18.913225  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4910,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:18.913766  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:19.111892  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.198s	user 0.137s	sys 0.059s Metrics: {"cfile_cache_miss":542,"cfile_cache_miss_bytes":25184930,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":711,"lbm_read_time_us":13471,"lbm_reads_lt_1ms":574,"lbm_write_time_us":34473,"lbm_writes_lt_1ms":553,"mutex_wait_us":55,"peak_mem_usage":63526250,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2550}
I20260812 06:19:19.112591  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=14.095187
I20260812 06:19:19.181941  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.069s	user 0.023s	sys 0.038s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27926,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.182710  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=3.181125
I20260812 06:19:19.197016  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":5251341,"delete_count":0,"lbm_write_time_us":5863,"lbm_writes_lt_1ms":131,"reinsert_count":0,"update_count":640}
I20260812 06:19:19.197552  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=1.196750
I20260812 06:19:19.205446  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.008s	user 0.003s	sys 0.003s Metrics: {"bytes_written":2543704,"delete_count":0,"lbm_write_time_us":2729,"lbm_writes_lt_1ms":65,"reinsert_count":0,"update_count":310}
I20260812 06:19:19.206029  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:19.419785  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.214s	user 0.126s	sys 0.087s Metrics: {"cfile_cache_miss":623,"cfile_cache_miss_bytes":28466940,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":942,"lbm_read_time_us":15420,"lbm_reads_lt_1ms":663,"lbm_write_time_us":34329,"lbm_writes_lt_1ms":633,"mutex_wait_us":26,"peak_mem_usage":74091738,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2950}
I20260812 06:19:19.420557  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=14.095187
I20260812 06:19:19.478736  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.058s	user 0.021s	sys 0.036s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26548,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.479400  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:19.507550  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.028s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6334,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.508150  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:19.524194  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6145,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.524926  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:19.740774  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.216s	user 0.120s	sys 0.095s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1472,"lbm_read_time_us":14916,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35816,"lbm_writes_lt_1ms":643,"mutex_wait_us":597,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":23424,"update_count":3000}
I20260812 06:19:19.741619  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=14.095187
I20260812 06:19:19.803776  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.062s	user 0.042s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":29212,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.804384  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:19.829119  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.025s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5299,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.829718  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=2.188937
I20260812 06:19:19.845811  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6034,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.846755  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushMRSOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:19.882247  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushMRSOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.035s	user 0.025s	sys 0.009s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":252,"dirs.run_wall_time_us":1480,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2320,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:19.883100  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling LogGCOp(79b86705eb6843229121212619a51e22): free 129320840 bytes of WAL
I20260812 06:19:19.883355  6937 log_reader.cc:385] T 79b86705eb6843229121212619a51e22: removed 13 log segments from log reader
I20260812 06:19:19.883404  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000027 (ops 130-134)
I20260812 06:19:19.883435  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000028 (ops 135-138)
I20260812 06:19:19.883502  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000029 (ops 139-143)
I20260812 06:19:19.883536  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000030 (ops 144-148)
I20260812 06:19:19.883579  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000031 (ops 149-153)
I20260812 06:19:19.883641  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000032 (ops 154-158)
I20260812 06:19:19.883685  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000033 (ops 159-163)
I20260812 06:19:19.883728  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000034 (ops 164-168)
I20260812 06:19:19.883773  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000035 (ops 169-172)
I20260812 06:19:19.883814  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000036 (ops 173-177)
I20260812 06:19:19.883858  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000037 (ops 178-182)
I20260812 06:19:19.883895  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000038 (ops 183-187)
I20260812 06:19:19.883934  6937 log.cc:1079] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/79b86705eb6843229121212619a51e22/wal-000000039 (ops 188-192)
I20260812 06:19:19.914150  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: LogGCOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.031s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:19.914765  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling UndoDeltaBlockGCOp(79b86705eb6843229121212619a51e22): 473 bytes on disk
I20260812 06:19:19.915237  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: UndoDeltaBlockGCOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:19.915894  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=4.173312
I20260812 06:19:19.930439  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":5333393,"delete_count":0,"lbm_write_time_us":5821,"lbm_writes_lt_1ms":133,"reinsert_count":0,"update_count":650}
I20260812 06:19:19.930981  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=1.196750
I20260812 06:19:19.941730  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.011s	user 0.001s	sys 0.006s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":3056,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:19:19.942339  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22): perf score=1.000000
I20260812 06:19:20.069723  6760 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.105s	user 1.821s	sys 0.193s
I20260812 06:19:20.196622  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: MajorDeltaCompactionOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.254s	user 0.164s	sys 0.078s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082258,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":951,"lbm_read_time_us":18680,"lbm_reads_lt_1ms":863,"lbm_write_time_us":42030,"lbm_writes_lt_1ms":843,"mutex_wait_us":33,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":6400,"thread_start_us":106,"threads_started":1,"update_count":4000}
I20260812 06:19:20.197444  7033 maintenance_manager.cc:419] P c54694640a8d4c3db49b18a89f9537df: Scheduling FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22): perf score=10.126437
I20260812 06:19:20.205394  6760 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.135s	user 0.002s	sys 0.002s
I20260812 06:19:20.206288  6760 tablet_server.cc:179] TabletServer@127.6.154.1:0 shutting down...
I20260812 06:19:20.237648  6937 maintenance_manager.cc:643] P c54694640a8d4c3db49b18a89f9537df: FlushDeltaMemStoresOp(79b86705eb6843229121212619a51e22) complete. Timing: real 0.040s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17231,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:20.238322  6760 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:20.238792  6760 tablet_replica.cc:333] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df: stopping tablet replica
I20260812 06:19:20.239053  6760 raft_consensus.cc:2243] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:20.239292  6760 raft_consensus.cc:2272] T 79b86705eb6843229121212619a51e22 P c54694640a8d4c3db49b18a89f9537df [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:20.245198  6760 tablet_server.cc:196] TabletServer@127.6.154.1:0 shutdown complete.
I20260812 06:19:20.270504  6760 master.cc:562] Master@127.6.154.62:45359 shutting down...
I20260812 06:19:20.274555  6760 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:20.274924  6760 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:20.275009  6760 tablet_replica.cc:333] T 00000000000000000000000000000000 P 180426182ba244f186f355a626b991d2: stopping tablet replica
I20260812 06:19:20.287811  6760 master.cc:584] Master@127.6.154.62:45359 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5678 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:20.384686  6760 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.6.154.62:36655
I20260812 06:19:20.385110  6760 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:20.387687  7090 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:20.387797  6760 server_base.cc:1061] running on GCE node
W20260812 06:19:20.387807  7095 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:20.387807  7087 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:20.388335  6760 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:20.388409  6760 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:20.388437  6760 hybrid_clock.cc:648] HybridClock initialized: now 1786515560388436 us; error 0 us; skew 500 ppm
I20260812 06:19:20.389437  6760 webserver.cc:533] Webserver started at http://127.6.154.62:41727/ using document root <none> and password file <none>
I20260812 06:19:20.389645  6760 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:20.389729  6760 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:20.389891  6760 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:20.390341  6760 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/master-0-root/instance:
uuid: "ff2c686978e94eeea4a11a5b7e5179d2"
format_stamp: "Formatted at 2026-08-12 06:19:20 on dist-test-slave-3kk6"
I20260812 06:19:20.392102  6760 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:20.393344  7102 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:20.393721  6760 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:20.393831  6760 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/master-0-root
uuid: "ff2c686978e94eeea4a11a5b7e5179d2"
format_stamp: "Formatted at 2026-08-12 06:19:20 on dist-test-slave-3kk6"
I20260812 06:19:20.393962  6760 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-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:20.406934  6760 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:20.407425  6760 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:20.412371  6760 rpc_server.cc:307] RPC server started. Bound to: 127.6.154.62:36655
I20260812 06:19:20.413913  7214 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.154.62:36655 every 8 connection(s)
I20260812 06:19:20.419435  7216 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:20.430496  7216 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2: Bootstrap starting.
I20260812 06:19:20.431478  7216 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:20.432814  7216 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2: No bootstrap required, opened a new log
I20260812 06:19:20.433251  7216 raft_consensus.cc:359] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff2c686978e94eeea4a11a5b7e5179d2" member_type: VOTER }
I20260812 06:19:20.433360  7216 raft_consensus.cc:385] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:20.433385  7216 raft_consensus.cc:740] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ff2c686978e94eeea4a11a5b7e5179d2, State: Initialized, Role: FOLLOWER
I20260812 06:19:20.433507  7216 consensus_queue.cc:260] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [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: "ff2c686978e94eeea4a11a5b7e5179d2" member_type: VOTER }
I20260812 06:19:20.433620  7216 raft_consensus.cc:399] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:20.433672  7216 raft_consensus.cc:493] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:20.433758  7216 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:20.434621  7216 raft_consensus.cc:515] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff2c686978e94eeea4a11a5b7e5179d2" member_type: VOTER }
I20260812 06:19:20.434859  7216 leader_election.cc:304] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [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: ff2c686978e94eeea4a11a5b7e5179d2; no voters: 
I20260812 06:19:20.435123  7216 leader_election.cc:290] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:20.435316  7221 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:20.435623  7221 raft_consensus.cc:697] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [term 1 LEADER]: Becoming Leader. State: Replica: ff2c686978e94eeea4a11a5b7e5179d2, State: Running, Role: LEADER
I20260812 06:19:20.435755  7216 sys_catalog.cc:565] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:20.435801  7221 consensus_queue.cc:237] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [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: "ff2c686978e94eeea4a11a5b7e5179d2" member_type: VOTER }
I20260812 06:19:20.436445  7226 sys_catalog.cc:455] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader ff2c686978e94eeea4a11a5b7e5179d2. Latest consensus state: current_term: 1 leader_uuid: "ff2c686978e94eeea4a11a5b7e5179d2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff2c686978e94eeea4a11a5b7e5179d2" member_type: VOTER } }
I20260812 06:19:20.436578  7226 sys_catalog.cc:458] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:20.436419  7225 sys_catalog.cc:455] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ff2c686978e94eeea4a11a5b7e5179d2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff2c686978e94eeea4a11a5b7e5179d2" member_type: VOTER } }
I20260812 06:19:20.436741  7225 sys_catalog.cc:458] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:20.437373  7236 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:20.438190  7236 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:20.438517  6760 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:20.440236  7236 catalog_manager.cc:1383] Generated new cluster ID: bd0dbac0332d45c69464b493c4f14f0e
I20260812 06:19:20.440301  7236 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:20.451879  7236 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:20.452529  7236 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:20.466393  7236 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2: Generated new TSK 0
I20260812 06:19:20.466714  7236 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:20.471243  6760 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:20.473558  7257 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:20.473762  6760 server_base.cc:1061] running on GCE node
W20260812 06:19:20.473683  7255 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:20.473680  7264 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:20.474103  6760 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:20.474153  6760 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:20.474170  6760 hybrid_clock.cc:648] HybridClock initialized: now 1786515560474171 us; error 0 us; skew 500 ppm
I20260812 06:19:20.475171  6760 webserver.cc:533] Webserver started at http://127.6.154.1:35559/ using document root <none> and password file <none>
I20260812 06:19:20.475363  6760 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:20.475449  6760 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:20.475546  6760 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:20.475972  6760 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/instance:
uuid: "24a1b015c46e452e8785d51412b5fc85"
format_stamp: "Formatted at 2026-08-12 06:19:20 on dist-test-slave-3kk6"
I20260812 06:19:20.477632  6760 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:20.478780  7274 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:20.479053  6760 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:20.479148  6760 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root
uuid: "24a1b015c46e452e8785d51412b5fc85"
format_stamp: "Formatted at 2026-08-12 06:19:20 on dist-test-slave-3kk6"
I20260812 06:19:20.479245  6760 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-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:20.498402  6760 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:20.498980  6760 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:20.499392  6760 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:20.499975  6760 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:20.500041  6760 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:20.500123  6760 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:20.500180  6760 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:20.505013  6760 rpc_server.cc:307] RPC server started. Bound to: 127.6.154.1:34155
I20260812 06:19:20.505193  7383 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.154.1:34155 every 8 connection(s)
I20260812 06:19:20.515558  7387 heartbeater.cc:344] Connected to a master server at 127.6.154.62:36655
I20260812 06:19:20.515740  7387 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:20.516053  7387 heartbeater.cc:507] Master 127.6.154.62:36655 requested a full tablet report, sending...
I20260812 06:19:20.516857  7134 ts_manager.cc:194] Registered new tserver with Master: 24a1b015c46e452e8785d51412b5fc85 (127.6.154.1:34155)
I20260812 06:19:20.517694  7134 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51112
I20260812 06:19:20.517885  6760 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01230523s
I20260812 06:19:20.527002  7134 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51114:
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:20.537199  7319 tablet_service.cc:1511] Processing CreateTablet for tablet ad2b71c377c94743bf5d6a342c1b1fe5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=a1cc3d70ec5e48afad73718c055c764a]), partition=
I20260812 06:19:20.537540  7319 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ad2b71c377c94743bf5d6a342c1b1fe5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:20.539984  7409 tablet_bootstrap.cc:492] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Bootstrap starting.
I20260812 06:19:20.540956  7409 tablet_bootstrap.cc:654] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:20.542224  7409 tablet_bootstrap.cc:492] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: No bootstrap required, opened a new log
I20260812 06:19:20.542358  7409 ts_tablet_manager.cc:1403] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:20.542953  7409 raft_consensus.cc:359] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "24a1b015c46e452e8785d51412b5fc85" member_type: VOTER last_known_addr { host: "127.6.154.1" port: 34155 } }
I20260812 06:19:20.543095  7409 raft_consensus.cc:385] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:20.543143  7409 raft_consensus.cc:740] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 24a1b015c46e452e8785d51412b5fc85, State: Initialized, Role: FOLLOWER
I20260812 06:19:20.543296  7409 consensus_queue.cc:260] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85 [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: "24a1b015c46e452e8785d51412b5fc85" member_type: VOTER last_known_addr { host: "127.6.154.1" port: 34155 } }
I20260812 06:19:20.543412  7409 raft_consensus.cc:399] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:20.543459  7409 raft_consensus.cc:493] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:20.543515  7409 raft_consensus.cc:3060] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:20.544339  7409 raft_consensus.cc:515] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "24a1b015c46e452e8785d51412b5fc85" member_type: VOTER last_known_addr { host: "127.6.154.1" port: 34155 } }
I20260812 06:19:20.544510  7409 leader_election.cc:304] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85 [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: 24a1b015c46e452e8785d51412b5fc85; no voters: 
I20260812 06:19:20.544802  7409 leader_election.cc:290] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:20.544956  7416 raft_consensus.cc:2804] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:20.545212  7416 raft_consensus.cc:697] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85 [term 1 LEADER]: Becoming Leader. State: Replica: 24a1b015c46e452e8785d51412b5fc85, State: Running, Role: LEADER
I20260812 06:19:20.545187  7409 ts_tablet_manager.cc:1434] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:20.545202  7387 heartbeater.cc:499] Master 127.6.154.62:36655 was elected leader, sending a full tablet report...
I20260812 06:19:20.545390  7416 consensus_queue.cc:237] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85 [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: "24a1b015c46e452e8785d51412b5fc85" member_type: VOTER last_known_addr { host: "127.6.154.1" port: 34155 } }
I20260812 06:19:20.546924  7134 catalog_manager.cc:5719] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85 reported cstate change: term changed from 0 to 1, leader changed from <none> to 24a1b015c46e452e8785d51412b5fc85 (127.6.154.1). New cstate: current_term: 1 leader_uuid: "24a1b015c46e452e8785d51412b5fc85" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "24a1b015c46e452e8785d51412b5fc85" member_type: VOTER last_known_addr { host: "127.6.154.1" port: 34155 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:20.613554  6760 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.014s	sys 0.011s
I20260812 06:19:20.756215  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushMRSOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=15.086190
I20260812 06:19:20.895195  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushMRSOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.139s	user 0.095s	sys 0.041s Metrics: {"bytes_written":11897250,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":962,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35831,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":2304,"update_count":1450}
I20260812 06:19:20.895926  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling LogGCOp(ad2b71c377c94743bf5d6a342c1b1fe5): free 20743880 bytes of WAL
I20260812 06:19:20.896170  7281 log_reader.cc:385] T ad2b71c377c94743bf5d6a342c1b1fe5: removed 2 log segments from log reader
I20260812 06:19:20.896226  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000001 (ops 1-6)
I20260812 06:19:20.896282  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000002 (ops 7-11)
I20260812 06:19:20.900614  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: LogGCOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:20.900972  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:20.913591  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.914182  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling UndoDeltaBlockGCOp(ad2b71c377c94743bf5d6a342c1b1fe5): 12719214 bytes on disk
I20260812 06:19:20.914861  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: UndoDeltaBlockGCOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":96,"lbm_reads_lt_1ms":4}
I20260812 06:19:20.915427  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:21.060282  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.145s	user 0.113s	sys 0.031s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262037,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":596,"lbm_read_time_us":11050,"lbm_reads_lt_1ms":454,"lbm_write_time_us":27536,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"thread_start_us":433,"threads_started":5,"update_count":1950}
I20260812 06:19:21.061180  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=10.126437
I20260812 06:19:21.101688  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.040s	user 0.019s	sys 0.011s Metrics: {"bytes_written":12430562,"delete_count":0,"lbm_write_time_us":14890,"lbm_writes_lt_1ms":306,"reinsert_count":0,"update_count":1515}
I20260812 06:19:21.102281  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:21.114120  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":4542,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:19:21.114755  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:21.256310  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.141s	user 0.116s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":500,"lbm_read_time_us":10458,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27169,"lbm_writes_lt_1ms":443,"mutex_wait_us":113,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:19:21.256855  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=10.126437
I20260812 06:19:21.299494  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.042s	user 0.018s	sys 0.023s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":13070,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:21.300102  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:21.311419  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4556,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.312033  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:21.482771  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.171s	user 0.107s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":887,"lbm_read_time_us":12873,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28594,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:19:21.483385  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=11.118625
I20260812 06:19:21.520830  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.037s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16688,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:21.521719  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:21.536705  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.015s	user 0.000s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5119,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:21.537356  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:21.683528  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.146s	user 0.093s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":148,"lbm_read_time_us":10433,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28018,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2000}
I20260812 06:19:21.684278  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=11.118625
I20260812 06:19:21.716550  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.032s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14242,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:21.717338  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:21.735507  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.018s	user 0.008s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6348,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:21.736253  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:21.878917  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.142s	user 0.101s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":425,"lbm_read_time_us":9462,"lbm_reads_lt_1ms":464,"lbm_write_time_us":29330,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2000}
I20260812 06:19:21.879704  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=10.126437
I20260812 06:19:21.925599  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.046s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16031,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:21.926141  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:21.937988  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4181,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.938855  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:22.084596  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.146s	user 0.106s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":158,"lbm_read_time_us":9983,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29306,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20096,"update_count":2000}
I20260812 06:19:22.085284  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=10.126437
I20260812 06:19:22.136175  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.051s	user 0.020s	sys 0.029s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18184,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.136808  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:22.148343  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4582,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.148869  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:22.303844  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.155s	user 0.098s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":259,"lbm_read_time_us":11476,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24720,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":2000}
I20260812 06:19:22.304771  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=10.126437
I20260812 06:19:22.348762  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.044s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18648,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.349362  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:22.362560  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.013s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4318,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.363234  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushMRSOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:22.392009  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushMRSOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.029s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":274,"dirs.run_wall_time_us":1337,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1761,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:22.392601  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling LogGCOp(ad2b71c377c94743bf5d6a342c1b1fe5): free 124257254 bytes of WAL
I20260812 06:19:22.392829  7281 log_reader.cc:385] T ad2b71c377c94743bf5d6a342c1b1fe5: removed 12 log segments from log reader
I20260812 06:19:22.392892  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000003 (ops 12-16)
I20260812 06:19:22.392958  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000004 (ops 17-21)
I20260812 06:19:22.392999  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000005 (ops 22-26)
I20260812 06:19:22.393039  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000006 (ops 27-31)
I20260812 06:19:22.393076  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000007 (ops 32-36)
I20260812 06:19:22.393113  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000008 (ops 37-41)
I20260812 06:19:22.393150  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000009 (ops 42-46)
I20260812 06:19:22.393188  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000010 (ops 47-51)
I20260812 06:19:22.393229  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000011 (ops 52-56)
I20260812 06:19:22.393265  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000012 (ops 57-61)
I20260812 06:19:22.393307  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000013 (ops 62-66)
I20260812 06:19:22.393344  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000014 (ops 67-70)
I20260812 06:19:22.424054  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: LogGCOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:19:22.424705  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=3.181125
I20260812 06:19:22.449345  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.024s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4823,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:22.449939  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:22.460323  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3870,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:22.461045  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling UndoDeltaBlockGCOp(ad2b71c377c94743bf5d6a342c1b1fe5): 481 bytes on disk
I20260812 06:19:22.461709  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: UndoDeltaBlockGCOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:19:22.462370  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:22.685506  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.223s	user 0.153s	sys 0.068s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2653,"lbm_read_time_us":16010,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36408,"lbm_writes_lt_1ms":643,"mutex_wait_us":1686,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":27136,"thread_start_us":135,"threads_started":1,"update_count":3000}
I20260812 06:19:22.686270  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=14.095187
I20260812 06:19:22.748710  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.062s	user 0.040s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21743,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.749424  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:22.777902  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.028s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5849,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.778462  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:22.789804  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4368,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.790346  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:22.999228  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.209s	user 0.117s	sys 0.091s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":14744,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33071,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3000}
I20260812 06:19:23.002983  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=14.095187
I20260812 06:19:23.072728  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.068s	user 0.030s	sys 0.032s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":29119,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.073611  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:23.091919  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.018s	user 0.001s	sys 0.016s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7138,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.092604  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:23.284734  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.192s	user 0.144s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":390,"lbm_read_time_us":12585,"lbm_reads_lt_1ms":568,"lbm_write_time_us":34458,"lbm_writes_lt_1ms":543,"mutex_wait_us":78,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":2500}
I20260812 06:19:23.285490  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=14.095187
I20260812 06:19:23.358254  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.073s	user 0.015s	sys 0.054s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26058,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.359014  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:23.373593  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5401,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.374275  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:23.550117  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.176s	user 0.107s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":625,"lbm_read_time_us":10826,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29571,"lbm_writes_lt_1ms":543,"mutex_wait_us":304,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:23.550727  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=14.095187
I20260812 06:19:23.615585  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.065s	user 0.017s	sys 0.046s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22890,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.616153  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:23.629300  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.013s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4404,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.629891  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:23.812958  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.183s	user 0.097s	sys 0.079s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":783,"lbm_read_time_us":11692,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28591,"lbm_writes_lt_1ms":543,"mutex_wait_us":169,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:23.813683  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=15.087375
I20260812 06:19:23.883935  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.070s	user 0.023s	sys 0.036s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":22080,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:23.884589  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=6.157687
I20260812 06:19:23.905275  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.020s	user 0.013s	sys 0.005s Metrics: {"bytes_written":7794837,"delete_count":0,"lbm_write_time_us":8329,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:23.905952  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushMRSOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:23.941284  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushMRSOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.035s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":98,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1382,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2134,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:23.942001  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling LogGCOp(ad2b71c377c94743bf5d6a342c1b1fe5): free 120553382 bytes of WAL
I20260812 06:19:23.942233  7281 log_reader.cc:385] T ad2b71c377c94743bf5d6a342c1b1fe5: removed 12 log segments from log reader
I20260812 06:19:23.942294  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000015 (ops 71-75)
I20260812 06:19:23.942349  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000016 (ops 76-80)
I20260812 06:19:23.942409  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000017 (ops 81-85)
I20260812 06:19:23.942451  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000018 (ops 86-90)
I20260812 06:19:23.942488  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000019 (ops 91-94)
I20260812 06:19:23.942538  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000020 (ops 95-99)
I20260812 06:19:23.942574  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000021 (ops 100-104)
I20260812 06:19:23.942613  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000022 (ops 105-109)
I20260812 06:19:23.942674  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000023 (ops 110-114)
I20260812 06:19:23.942720  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000024 (ops 115-119)
I20260812 06:19:23.942761  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000025 (ops 120-124)
I20260812 06:19:23.942813  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000026 (ops 125-128)
I20260812 06:19:23.971529  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: LogGCOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.029s	user 0.003s	sys 0.025s Metrics: {}
I20260812 06:19:23.971990  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling UndoDeltaBlockGCOp(ad2b71c377c94743bf5d6a342c1b1fe5): 463 bytes on disk
I20260812 06:19:23.972457  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: UndoDeltaBlockGCOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:19:23.972994  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=3.181125
I20260812 06:19:23.989224  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.016s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4503,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:23.989765  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:24.001758  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4568,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:24.002331  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:24.258365  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.256s	user 0.166s	sys 0.087s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082152,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1663,"lbm_read_time_us":18001,"lbm_reads_lt_1ms":874,"lbm_write_time_us":43198,"lbm_writes_lt_1ms":843,"mutex_wait_us":25,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":10240,"thread_start_us":95,"threads_started":1,"update_count":4000}
I20260812 06:19:24.259228  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=18.063937
I20260812 06:19:24.320463  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.061s	user 0.047s	sys 0.012s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":28057,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:24.321492  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:24.354058  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.032s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7079,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.354611  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:24.368155  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.013s	user 0.002s	sys 0.010s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4860,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.368713  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:24.569041  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.200s	user 0.151s	sys 0.048s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979632,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":240,"lbm_read_time_us":15026,"lbm_reads_lt_1ms":773,"lbm_write_time_us":42059,"lbm_writes_lt_1ms":743,"mutex_wait_us":31,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":3500}
I20260812 06:19:24.569732  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=14.095187
I20260812 06:19:24.625490  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.055s	user 0.026s	sys 0.026s Metrics: {"bytes_written":16450926,"delete_count":0,"lbm_write_time_us":23951,"lbm_writes_lt_1ms":404,"reinsert_count":0,"update_count":2005}
I20260812 06:19:24.626292  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:24.642720  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.016s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":6011,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:19:24.643363  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:24.803582  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.160s	user 0.113s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1193,"lbm_read_time_us":9899,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30472,"lbm_writes_lt_1ms":543,"mutex_wait_us":315,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:19:24.804313  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=14.095187
I20260812 06:19:24.858801  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.054s	user 0.045s	sys 0.009s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24446,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:24.859552  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:24.872596  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4956,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.873087  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:25.062918  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.190s	user 0.103s	sys 0.084s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":398,"lbm_read_time_us":11825,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34309,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18560,"update_count":2500}
I20260812 06:19:25.063832  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=14.095187
I20260812 06:19:25.119221  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.055s	user 0.031s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22481,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.119769  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:25.278231  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.158s	user 0.107s	sys 0.038s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":858,"lbm_read_time_us":10266,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23924,"lbm_writes_lt_1ms":443,"mutex_wait_us":314,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2000}
I20260812 06:19:25.278925  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=14.095187
I20260812 06:19:25.326607  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.047s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20091,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.327266  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:25.339680  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4290,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.340246  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushMRSOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:25.379629  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushMRSOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.039s	user 0.037s	sys 0.001s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":1296,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1721,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:25.380651  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling LogGCOp(ad2b71c377c94743bf5d6a342c1b1fe5): free 112692612 bytes of WAL
I20260812 06:19:25.380925  7281 log_reader.cc:385] T ad2b71c377c94743bf5d6a342c1b1fe5: removed 11 log segments from log reader
I20260812 06:19:25.380988  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000027 (ops 129-133)
I20260812 06:19:25.381042  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000028 (ops 134-138)
I20260812 06:19:25.381078  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000029 (ops 139-143)
I20260812 06:19:25.381119  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000030 (ops 144-148)
I20260812 06:19:25.381153  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000031 (ops 149-153)
I20260812 06:19:25.381191  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000032 (ops 154-158)
I20260812 06:19:25.381228  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000033 (ops 159-163)
I20260812 06:19:25.381266  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000034 (ops 164-168)
I20260812 06:19:25.381302  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000035 (ops 169-173)
I20260812 06:19:25.381340  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000036 (ops 174-178)
I20260812 06:19:25.381376  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000037 (ops 179-183)
I20260812 06:19:25.406514  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: LogGCOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:25.407016  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:25.423841  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.017s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4726,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.424391  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling LogGCOp(ad2b71c377c94743bf5d6a342c1b1fe5): free 12017954 bytes of WAL
I20260812 06:19:25.424629  7281 log_reader.cc:385] T ad2b71c377c94743bf5d6a342c1b1fe5: removed 1 log segments from log reader
I20260812 06:19:25.424679  7281 log.cc:1079] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: Deleting log segment in path: /tmp/dist-test-taskxPdMF9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554695520-6760-0/minicluster-data/ts-0-root/wals/ad2b71c377c94743bf5d6a342c1b1fe5/wal-000000038 (ops 184-188)
I20260812 06:19:25.427174  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: LogGCOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:25.427516  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling UndoDeltaBlockGCOp(ad2b71c377c94743bf5d6a342c1b1fe5): 447 bytes on disk
I20260812 06:19:25.427954  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: UndoDeltaBlockGCOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:19:25.428467  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=2.188937
I20260812 06:19:25.440645  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.012s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4238,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.441195  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:25.709640  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.268s	user 0.168s	sys 0.091s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":773,"lbm_read_time_us":17103,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42287,"lbm_writes_lt_1ms":743,"mutex_wait_us":100,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":93,"threads_started":1,"update_count":3500}
I20260812 06:19:25.711102  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=18.063937
I20260812 06:19:25.780283  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: FlushDeltaMemStoresOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.069s	user 0.049s	sys 0.017s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":30740,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:25.781076  7388 maintenance_manager.cc:419] P 24a1b015c46e452e8785d51412b5fc85: Scheduling MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5): perf score=1.000000
I20260812 06:19:25.793418  6760 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.180s	user 1.849s	sys 0.217s
I20260812 06:19:25.867431  6760 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.073s	user 0.002s	sys 0.000s
I20260812 06:19:25.867997  6760 tablet_server.cc:179] TabletServer@127.6.154.1:0 shutting down...
I20260812 06:19:25.938284  7281 maintenance_manager.cc:643] P 24a1b015c46e452e8785d51412b5fc85: MajorDeltaCompactionOp(ad2b71c377c94743bf5d6a342c1b1fe5) complete. Timing: real 0.157s	user 0.096s	sys 0.060s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774573,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":291,"lbm_read_time_us":13130,"lbm_reads_lt_1ms":559,"lbm_write_time_us":26312,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":95744,"update_count":2500}
I20260812 06:19:25.939078  6760 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:25.939390  6760 tablet_replica.cc:333] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85: stopping tablet replica
I20260812 06:19:25.939601  6760 raft_consensus.cc:2243] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:25.939821  6760 raft_consensus.cc:2272] T ad2b71c377c94743bf5d6a342c1b1fe5 P 24a1b015c46e452e8785d51412b5fc85 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:25.957422  6760 tablet_server.cc:196] TabletServer@127.6.154.1:0 shutdown complete.
I20260812 06:19:25.984226  6760 master.cc:562] Master@127.6.154.62:36655 shutting down...
I20260812 06:19:25.988034  6760 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:25.988273  6760 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:25.988449  6760 tablet_replica.cc:333] T 00000000000000000000000000000000 P ff2c686978e94eeea4a11a5b7e5179d2: stopping tablet replica
I20260812 06:19:26.000952  6760 master.cc:584] Master@127.6.154.62:36655 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5710 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11389 ms total)

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