[==========] 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:17:23.144918  5790 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.167.190:39397
I20260812 06:17:23.145939  5790 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:17:23.146584  5790 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:23.153308  5799 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:17:23.153363  5797 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:17:23.153517  5790 server_base.cc:1061] running on GCE node
W20260812 06:17:23.153604  5796 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:17:23.154136  5790 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:23.154281  5790 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:17:23.154331  5790 hybrid_clock.cc:648] HybridClock initialized: now 1786515443154329 us; error 0 us; skew 500 ppm
I20260812 06:17:23.156131  5790 webserver.cc:533] Webserver started at http://127.5.167.190:44475/ using document root <none> and password file <none>
I20260812 06:17:23.156754  5790 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:23.156837  5790 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:23.157104  5790 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:23.158766  5790 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/master-0-root/instance:
uuid: "1f99f0ab5d36439aaf116d0178337ed4"
format_stamp: "Formatted at 2026-08-12 06:17:23 on dist-test-slave-8n49"
I20260812 06:17:23.162382  5790 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:17:23.164517  5804 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:17:23.165830  5790 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:23.165979  5790 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/master-0-root
uuid: "1f99f0ab5d36439aaf116d0178337ed4"
format_stamp: "Formatted at 2026-08-12 06:17:23 on dist-test-slave-8n49"
I20260812 06:17:23.166105  5790 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-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:17:23.187065  5790 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:23.187794  5790 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:17:23.188000  5790 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:23.195565  5790 rpc_server.cc:307] RPC server started. Bound to: 127.5.167.190:39397
I20260812 06:17:23.195608  5866 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.167.190:39397 every 8 connection(s)
I20260812 06:17:23.198336  5867 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:17:23.204006  5867 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4: Bootstrap starting.
I20260812 06:17:23.206564  5867 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:23.207545  5867 log.cc:826] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:23.209328  5867 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4: No bootstrap required, opened a new log
I20260812 06:17:23.212178  5867 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1f99f0ab5d36439aaf116d0178337ed4" member_type: VOTER }
I20260812 06:17:23.212347  5867 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:23.212466  5867 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1f99f0ab5d36439aaf116d0178337ed4, State: Initialized, Role: FOLLOWER
I20260812 06:17:23.213179  5867 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [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: "1f99f0ab5d36439aaf116d0178337ed4" member_type: VOTER }
I20260812 06:17:23.213351  5867 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:23.213443  5867 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:23.213599  5867 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:23.214511  5867 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1f99f0ab5d36439aaf116d0178337ed4" member_type: VOTER }
I20260812 06:17:23.214998  5867 leader_election.cc:304] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [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: 1f99f0ab5d36439aaf116d0178337ed4; no voters: 
I20260812 06:17:23.215358  5867 leader_election.cc:290] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:23.215517  5870 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:23.215806  5870 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [term 1 LEADER]: Becoming Leader. State: Replica: 1f99f0ab5d36439aaf116d0178337ed4, State: Running, Role: LEADER
I20260812 06:17:23.216250  5870 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [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: "1f99f0ab5d36439aaf116d0178337ed4" member_type: VOTER }
I20260812 06:17:23.216444  5867 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:23.218345  5873 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1f99f0ab5d36439aaf116d0178337ed4. Latest consensus state: current_term: 1 leader_uuid: "1f99f0ab5d36439aaf116d0178337ed4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1f99f0ab5d36439aaf116d0178337ed4" member_type: VOTER } }
I20260812 06:17:23.218384  5871 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1f99f0ab5d36439aaf116d0178337ed4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1f99f0ab5d36439aaf116d0178337ed4" member_type: VOTER } }
I20260812 06:17:23.218506  5873 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:23.218506  5871 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:23.218981  5885 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:23.219143  5790 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:23.221333  5885 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:23.225855  5885 catalog_manager.cc:1383] Generated new cluster ID: b7a0afcb445043129f0d56ed2451f8e4
I20260812 06:17:23.225934  5885 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:23.252141  5885 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:23.253429  5885 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:23.260224  5885 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4: Generated new TSK 0
I20260812 06:17:23.261071  5885 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:23.284605  5790 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:23.287958  5790 server_base.cc:1061] running on GCE node
W20260812 06:17:23.287945  5892 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:17:23.288133  5893 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:17:23.287945  5895 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:17:23.288585  5790 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:23.288643  5790 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:17:23.288686  5790 hybrid_clock.cc:648] HybridClock initialized: now 1786515443288684 us; error 0 us; skew 500 ppm
I20260812 06:17:23.289710  5790 webserver.cc:533] Webserver started at http://127.5.167.129:44465/ using document root <none> and password file <none>
I20260812 06:17:23.289904  5790 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:23.289978  5790 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:23.290067  5790 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:23.290495  5790 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/instance:
uuid: "74eaa168fe2a45a79ffecb3239ee9575"
format_stamp: "Formatted at 2026-08-12 06:17:23 on dist-test-slave-8n49"
I20260812 06:17:23.292099  5790 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:23.293377  5901 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:17:23.293674  5790 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:23.293747  5790 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root
uuid: "74eaa168fe2a45a79ffecb3239ee9575"
format_stamp: "Formatted at 2026-08-12 06:17:23 on dist-test-slave-8n49"
I20260812 06:17:23.293839  5790 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-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:17:23.305846  5790 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:23.306367  5790 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:23.306922  5790 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:23.307868  5790 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:23.307922  5790 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:23.307996  5790 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:23.308038  5790 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:23.315523  5790 rpc_server.cc:307] RPC server started. Bound to: 127.5.167.129:39219
I20260812 06:17:23.315588  5979 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.167.129:39219 every 8 connection(s)
I20260812 06:17:23.327103  5980 heartbeater.cc:344] Connected to a master server at 127.5.167.190:39397
I20260812 06:17:23.327410  5980 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:23.327939  5980 heartbeater.cc:507] Master 127.5.167.190:39397 requested a full tablet report, sending...
I20260812 06:17:23.329674  5825 ts_manager.cc:194] Registered new tserver with Master: 74eaa168fe2a45a79ffecb3239ee9575 (127.5.167.129:39219)
I20260812 06:17:23.329814  5790 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013652895s
I20260812 06:17:23.331370  5825 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52984
I20260812 06:17:23.341081  5825 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52988:
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:17:23.355904  5940 tablet_service.cc:1511] Processing CreateTablet for tablet ff34341d525e4be0af1d2fc4367a074e (DEFAULT_TABLE table=heavy-update-compaction-test [id=e8a1f162944d4ad8917de67bb6333324]), partition=
I20260812 06:17:23.356464  5940 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ff34341d525e4be0af1d2fc4367a074e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:23.360179  5994 tablet_bootstrap.cc:492] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Bootstrap starting.
I20260812 06:17:23.361182  5994 tablet_bootstrap.cc:654] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:23.362339  5994 tablet_bootstrap.cc:492] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: No bootstrap required, opened a new log
I20260812 06:17:23.362474  5994 ts_tablet_manager.cc:1403] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:23.362923  5994 raft_consensus.cc:359] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74eaa168fe2a45a79ffecb3239ee9575" member_type: VOTER last_known_addr { host: "127.5.167.129" port: 39219 } }
I20260812 06:17:23.363046  5994 raft_consensus.cc:385] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:23.363108  5994 raft_consensus.cc:740] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 74eaa168fe2a45a79ffecb3239ee9575, State: Initialized, Role: FOLLOWER
I20260812 06:17:23.363283  5994 consensus_queue.cc:260] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575 [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: "74eaa168fe2a45a79ffecb3239ee9575" member_type: VOTER last_known_addr { host: "127.5.167.129" port: 39219 } }
I20260812 06:17:23.363401  5994 raft_consensus.cc:399] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:23.363458  5994 raft_consensus.cc:493] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:23.363523  5994 raft_consensus.cc:3060] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:23.364874  5994 raft_consensus.cc:515] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74eaa168fe2a45a79ffecb3239ee9575" member_type: VOTER last_known_addr { host: "127.5.167.129" port: 39219 } }
I20260812 06:17:23.365042  5994 leader_election.cc:304] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575 [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: 74eaa168fe2a45a79ffecb3239ee9575; no voters: 
I20260812 06:17:23.365289  5994 leader_election.cc:290] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:23.365412  5996 raft_consensus.cc:2804] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:23.365686  5994 ts_tablet_manager.cc:1434] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:17:23.365705  5996 raft_consensus.cc:697] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575 [term 1 LEADER]: Becoming Leader. State: Replica: 74eaa168fe2a45a79ffecb3239ee9575, State: Running, Role: LEADER
I20260812 06:17:23.365947  5980 heartbeater.cc:499] Master 127.5.167.190:39397 was elected leader, sending a full tablet report...
I20260812 06:17:23.365958  5996 consensus_queue.cc:237] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575 [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: "74eaa168fe2a45a79ffecb3239ee9575" member_type: VOTER last_known_addr { host: "127.5.167.129" port: 39219 } }
I20260812 06:17:23.369257  5825 catalog_manager.cc:5719] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575 reported cstate change: term changed from 0 to 1, leader changed from <none> to 74eaa168fe2a45a79ffecb3239ee9575 (127.5.167.129). New cstate: current_term: 1 leader_uuid: "74eaa168fe2a45a79ffecb3239ee9575" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74eaa168fe2a45a79ffecb3239ee9575" member_type: VOTER last_known_addr { host: "127.5.167.129" port: 39219 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:23.442931  5790 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.019s	sys 0.009s
I20260812 06:17:23.567457  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushMRSOp(ff34341d525e4be0af1d2fc4367a074e): perf score=16.078378
I20260812 06:17:23.718933  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushMRSOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.151s	user 0.107s	sys 0.042s Metrics: {"bytes_written":8861469,"cfile_init":1,"compiler_manager_pool.queue_time_us":396,"delete_count":0,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":190,"dirs.run_wall_time_us":1096,"drs_written":1,"lbm_read_time_us":97,"lbm_reads_lt_1ms":4,"lbm_write_time_us":33364,"lbm_writes_lt_1ms":673,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":58112,"thread_start_us":163,"threads_started":1,"update_count":1080}
I20260812 06:17:23.720268  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling LogGCOp(ff34341d525e4be0af1d2fc4367a074e): free 20743880 bytes of WAL
I20260812 06:17:23.720605  5907 log_reader.cc:385] T ff34341d525e4be0af1d2fc4367a074e: removed 2 log segments from log reader
I20260812 06:17:23.720676  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000001 (ops 1-6)
I20260812 06:17:23.720782  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000002 (ops 7-11)
I20260812 06:17:23.725967  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: LogGCOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:17:23.726425  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:23.741568  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.015s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3446255,"delete_count":0,"lbm_write_time_us":4505,"lbm_writes_lt_1ms":87,"reinsert_count":0,"update_count":420}
I20260812 06:17:23.742262  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling UndoDeltaBlockGCOp(ff34341d525e4be0af1d2fc4367a074e): 16411395 bytes on disk
I20260812 06:17:23.742990  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: UndoDeltaBlockGCOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:17:23.743492  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:23.865057  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.121s	user 0.096s	sys 0.018s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569852,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":968,"lbm_read_time_us":7670,"lbm_reads_lt_1ms":360,"lbm_write_time_us":20242,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":374,"threads_started":5,"update_count":1500}
I20260812 06:17:23.865729  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=10.126437
I20260812 06:17:23.909875  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.044s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13744,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:23.910418  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:23.925840  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5670,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:23.926437  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:24.049453  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.123s	user 0.094s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":255,"lbm_read_time_us":8020,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23424,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2000}
I20260812 06:17:24.050110  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=10.126437
I20260812 06:17:24.097910  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.048s	user 0.019s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14172,"lbm_writes_lt_1ms":303,"mutex_wait_us":2,"reinsert_count":0,"update_count":1500}
I20260812 06:17:24.098451  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:24.108990  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3921,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.109452  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:24.247618  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.138s	user 0.088s	sys 0.049s 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":163,"lbm_read_time_us":10294,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23033,"lbm_writes_lt_1ms":443,"mutex_wait_us":74,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:24.248389  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=10.126437
I20260812 06:17:24.295006  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.046s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19276,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:24.295459  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:24.306756  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4065,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.307312  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:24.428356  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.121s	user 0.102s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":7803,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24354,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:17:24.428962  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=10.126437
I20260812 06:17:24.473814  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.045s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16919,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:24.474327  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:24.484835  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3981,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.485586  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:24.612033  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.126s	user 0.094s	sys 0.032s 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":937,"lbm_read_time_us":8947,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23793,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2000}
I20260812 06:17:24.612704  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=10.126437
I20260812 06:17:24.665337  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.052s	user 0.030s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18722,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:24.665973  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:24.677465  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4428,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.677953  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:24.825047  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.147s	user 0.109s	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":303,"lbm_read_time_us":10506,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25315,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:17:24.825767  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=10.126437
I20260812 06:17:24.873564  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.047s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16223,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:24.874106  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:24.886046  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4262,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.886523  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:25.011456  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.125s	user 0.098s	sys 0.025s 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":791,"lbm_read_time_us":9080,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23477,"lbm_writes_lt_1ms":443,"mutex_wait_us":467,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:25.012074  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=10.126437
I20260812 06:17:25.054533  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.042s	user 0.033s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18588,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:25.055162  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:25.071864  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6291,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.072340  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushMRSOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:25.108325  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushMRSOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.036s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":265,"dirs.run_wall_time_us":1626,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1563,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:25.109231  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling LogGCOp(ff34341d525e4be0af1d2fc4367a074e): free 121006444 bytes of WAL
I20260812 06:17:25.109477  5907 log_reader.cc:385] T ff34341d525e4be0af1d2fc4367a074e: removed 12 log segments from log reader
I20260812 06:17:25.109539  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000003 (ops 12-16)
I20260812 06:17:25.109591  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000004 (ops 17-21)
I20260812 06:17:25.109642  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000005 (ops 22-26)
I20260812 06:17:25.109685  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000006 (ops 27-31)
I20260812 06:17:25.109731  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000007 (ops 32-36)
I20260812 06:17:25.109776  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000008 (ops 37-41)
I20260812 06:17:25.109820  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000009 (ops 42-46)
I20260812 06:17:25.109862  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000010 (ops 47-50)
I20260812 06:17:25.109901  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000011 (ops 51-55)
I20260812 06:17:25.109941  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000012 (ops 56-60)
I20260812 06:17:25.109982  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000013 (ops 61-65)
I20260812 06:17:25.110021  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000014 (ops 66-70)
I20260812 06:17:25.138363  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: LogGCOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.029s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:17:25.138851  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling UndoDeltaBlockGCOp(ff34341d525e4be0af1d2fc4367a074e): 482 bytes on disk
I20260812 06:17:25.139396  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: UndoDeltaBlockGCOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:17:25.139895  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=3.181125
I20260812 06:17:25.157486  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4923146,"delete_count":0,"lbm_write_time_us":7211,"lbm_writes_lt_1ms":123,"reinsert_count":0,"update_count":600}
I20260812 06:17:25.158087  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:25.171953  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.014s	user 0.005s	sys 0.007s Metrics: {"bytes_written":3282155,"delete_count":0,"lbm_write_time_us":4961,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:17:25.172739  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:25.361958  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.189s	user 0.142s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877323,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":440,"lbm_read_time_us":13057,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36611,"lbm_writes_lt_1ms":643,"mutex_wait_us":42,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:17:25.362627  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=14.095187
I20260812 06:17:25.419836  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.057s	user 0.045s	sys 0.003s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24632,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:25.420305  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:25.432302  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.432806  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:25.585408  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.152s	user 0.116s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":238,"lbm_read_time_us":11522,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31621,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:17:25.586117  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=10.126437
I20260812 06:17:25.624087  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.038s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16528,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:25.624681  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:25.642143  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.017s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7175,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.642683  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:25.796360  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.153s	user 0.087s	sys 0.060s 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":164,"lbm_read_time_us":9483,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26352,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:25.797145  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=14.095187
I20260812 06:17:25.855809  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.058s	user 0.023s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27569,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:25.856372  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:25.874397  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.018s	user 0.003s	sys 0.013s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4979,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.874943  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:26.051481  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.176s	user 0.139s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":339,"lbm_read_time_us":13459,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30552,"lbm_writes_lt_1ms":543,"mutex_wait_us":59,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:17:26.052174  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=14.095187
I20260812 06:17:26.112977  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.061s	user 0.033s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28852,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.113591  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:26.136790  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.023s	user 0.011s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6487,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.137320  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:26.312012  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.175s	user 0.122s	sys 0.053s 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":472,"lbm_read_time_us":10841,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28412,"lbm_writes_lt_1ms":543,"mutex_wait_us":91,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2500}
I20260812 06:17:26.312932  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=14.095187
I20260812 06:17:26.371513  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.058s	user 0.046s	sys 0.009s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26088,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.372056  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:26.385471  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5039,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.385938  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:26.555212  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.169s	user 0.113s	sys 0.052s 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":149,"lbm_read_time_us":10874,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33463,"lbm_writes_lt_1ms":543,"mutex_wait_us":59,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:17:26.555862  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=14.095187
I20260812 06:17:26.613713  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.058s	user 0.042s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23730,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.614274  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:26.628338  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.014s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4955,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.628996  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushMRSOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:26.669504  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushMRSOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.040s	user 0.039s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":90,"dirs.run_cpu_time_us":307,"dirs.run_wall_time_us":1318,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2261,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:26.670574  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling LogGCOp(ff34341d525e4be0af1d2fc4367a074e): free 136275207 bytes of WAL
I20260812 06:17:26.670964  5907 log_reader.cc:385] T ff34341d525e4be0af1d2fc4367a074e: removed 13 log segments from log reader
I20260812 06:17:26.671067  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000015 (ops 71-75)
I20260812 06:17:26.671125  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000016 (ops 76-80)
I20260812 06:17:26.671166  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000017 (ops 81-85)
I20260812 06:17:26.671211  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000018 (ops 86-90)
I20260812 06:17:26.671263  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000019 (ops 91-95)
I20260812 06:17:26.671320  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000020 (ops 96-100)
I20260812 06:17:26.671360  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000021 (ops 101-104)
I20260812 06:17:26.671414  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000022 (ops 105-109)
I20260812 06:17:26.671444  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000023 (ops 110-114)
I20260812 06:17:26.671486  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000024 (ops 115-119)
I20260812 06:17:26.671517  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000025 (ops 120-124)
I20260812 06:17:26.671554  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000026 (ops 125-129)
I20260812 06:17:26.671597  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000027 (ops 130-134)
I20260812 06:17:26.703570  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: LogGCOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:26.704089  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=6.157687
I20260812 06:17:26.734434  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.030s	user 0.022s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11344,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:26.735050  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling UndoDeltaBlockGCOp(ff34341d525e4be0af1d2fc4367a074e): 483 bytes on disk
I20260812 06:17:26.735684  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: UndoDeltaBlockGCOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:17:26.736394  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:27.004995  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.268s	user 0.187s	sys 0.068s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979632,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":395,"lbm_read_time_us":16518,"lbm_reads_lt_1ms":765,"lbm_write_time_us":44714,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":89,"threads_started":1,"update_count":3500}
I20260812 06:17:27.005898  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=18.063937
I20260812 06:17:27.081017  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.075s	user 0.036s	sys 0.028s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28651,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:27.081702  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:27.099116  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6200,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.099783  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:27.302490  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.202s	user 0.138s	sys 0.063s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1381,"lbm_read_time_us":15597,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33706,"lbm_writes_lt_1ms":643,"mutex_wait_us":353,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":3000}
I20260812 06:17:27.303179  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=14.095187
I20260812 06:17:27.358839  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.055s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24685,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.359474  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:27.373517  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5203,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.374297  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:27.555646  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.181s	user 0.122s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":680,"lbm_read_time_us":13622,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30324,"lbm_writes_lt_1ms":543,"mutex_wait_us":296,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2500}
I20260812 06:17:27.556229  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=14.095187
I20260812 06:17:27.615214  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.059s	user 0.033s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":26454,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.615828  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:27.634126  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.018s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7112,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.635094  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:27.810066  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.175s	user 0.104s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":389,"lbm_read_time_us":11554,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29472,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:27.810716  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=14.095187
I20260812 06:17:27.876920  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.066s	user 0.039s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22167,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.877511  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:27.889103  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4477,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.889554  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:28.083387  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.194s	user 0.142s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":169,"lbm_read_time_us":13268,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32944,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:17:28.084203  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=10.126437
I20260812 06:17:28.122725  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.038s	user 0.027s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16564,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.123400  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:28.145753  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.022s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6737,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.146425  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:28.285023  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.138s	user 0.105s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":314,"lbm_read_time_us":7435,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27732,"lbm_writes_lt_1ms":443,"mutex_wait_us":85,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.285830  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=11.118625
I20260812 06:17:28.330140  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.044s	user 0.022s	sys 0.020s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":21866,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:17:28.330781  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:28.354413  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.023s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4871,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:28.354928  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=2.188937
I20260812 06:17:28.365507  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.010s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3870,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.365974  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushMRSOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:28.399827  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushMRSOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.034s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":1189,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1847,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:28.400626  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling LogGCOp(ff34341d525e4be0af1d2fc4367a074e): free 129773837 bytes of WAL
I20260812 06:17:28.400854  5907 log_reader.cc:385] T ff34341d525e4be0af1d2fc4367a074e: removed 13 log segments from log reader
I20260812 06:17:28.400902  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000028 (ops 135-139)
I20260812 06:17:28.400949  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000029 (ops 140-144)
I20260812 06:17:28.400993  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000030 (ops 145-148)
I20260812 06:17:28.401041  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000031 (ops 149-153)
I20260812 06:17:28.401079  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000032 (ops 154-158)
I20260812 06:17:28.401136  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000033 (ops 159-163)
I20260812 06:17:28.401178  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000034 (ops 164-168)
I20260812 06:17:28.401217  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000035 (ops 169-173)
I20260812 06:17:28.401260  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000036 (ops 174-178)
I20260812 06:17:28.401300  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000037 (ops 179-183)
I20260812 06:17:28.401340  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000038 (ops 184-188)
I20260812 06:17:28.401379  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000039 (ops 189-193)
I20260812 06:17:28.401419  5907 log.cc:1079] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/ff34341d525e4be0af1d2fc4367a074e/wal-000000040 (ops 194-198)
I20260812 06:17:28.429943  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: LogGCOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.029s	user 0.004s	sys 0.024s Metrics: {}
I20260812 06:17:28.430415  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=3.181125
I20260812 06:17:28.438038  5790 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.995s	user 1.873s	sys 0.118s
I20260812 06:17:28.444355  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":5251344,"delete_count":0,"lbm_write_time_us":6033,"lbm_writes_lt_1ms":131,"mutex_wait_us":136,"reinsert_count":0,"update_count":640}
I20260812 06:17:28.444993  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.196750
I20260812 06:17:28.453028  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: FlushDeltaMemStoresOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.008s	user 0.003s	sys 0.005s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":3014,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:17:28.453531  5982 maintenance_manager.cc:419] P 74eaa168fe2a45a79ffecb3239ee9575: Scheduling MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e): perf score=1.000000
I20260812 06:17:28.501094  5790 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.062s	user 0.003s	sys 0.000s
I20260812 06:17:28.501767  5790 tablet_server.cc:179] TabletServer@127.5.167.129:0 shutting down...
I20260812 06:17:28.608785  5907 maintenance_manager.cc:643] P 74eaa168fe2a45a79ffecb3239ee9575: MajorDeltaCompactionOp(ff34341d525e4be0af1d2fc4367a074e) complete. Timing: real 0.155s	user 0.104s	sys 0.049s Metrics: {"cfile_cache_hit":323,"cfile_cache_hit_bytes":13130428,"cfile_cache_miss":412,"cfile_cache_miss_bytes":19849407,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":3056,"lbm_read_time_us":7149,"lbm_reads_lt_1ms":448,"lbm_write_time_us":34665,"lbm_writes_lt_1ms":743,"mutex_wait_us":111,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":30080,"thread_start_us":96,"threads_started":1,"update_count":3500}
I20260812 06:17:28.609582  5790 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:28.610080  5790 tablet_replica.cc:333] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575: stopping tablet replica
I20260812 06:17:28.610286  5790 raft_consensus.cc:2243] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:28.610499  5790 raft_consensus.cc:2272] T ff34341d525e4be0af1d2fc4367a074e P 74eaa168fe2a45a79ffecb3239ee9575 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:28.626216  5790 tablet_server.cc:196] TabletServer@127.5.167.129:0 shutdown complete.
I20260812 06:17:28.665326  5790 master.cc:562] Master@127.5.167.190:39397 shutting down...
I20260812 06:17:28.668941  5790 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:28.669147  5790 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:28.669238  5790 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1f99f0ab5d36439aaf116d0178337ed4: stopping tablet replica
I20260812 06:17:28.681740  5790 master.cc:584] Master@127.5.167.190:39397 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5619 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:28.764469  5790 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.167.190:39719
I20260812 06:17:28.764882  5790 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:28.767287  5790 server_base.cc:1061] running on GCE node
W20260812 06:17:28.767350  6018 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:17:28.767371  6017 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:17:28.767635  6020 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:17:28.767833  5790 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:28.767887  5790 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:17:28.767903  5790 hybrid_clock.cc:648] HybridClock initialized: now 1786515448767904 us; error 0 us; skew 500 ppm
I20260812 06:17:28.768748  5790 webserver.cc:533] Webserver started at http://127.5.167.190:35103/ using document root <none> and password file <none>
I20260812 06:17:28.768929  5790 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:28.768978  5790 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:28.769033  5790 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:28.769430  5790 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/master-0-root/instance:
uuid: "94523c017f2a440cbdbe88a409e6bf81"
format_stamp: "Formatted at 2026-08-12 06:17:28 on dist-test-slave-8n49"
I20260812 06:17:28.771029  5790 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:28.772058  6026 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:17:28.772353  5790 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:28.772449  5790 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/master-0-root
uuid: "94523c017f2a440cbdbe88a409e6bf81"
format_stamp: "Formatted at 2026-08-12 06:17:28 on dist-test-slave-8n49"
I20260812 06:17:28.772513  5790 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-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:17:28.800199  5790 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:28.800624  5790 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:28.805006  5790 rpc_server.cc:307] RPC server started. Bound to: 127.5.167.190:39719
I20260812 06:17:28.807091  6093 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:17:28.809888  6092 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.167.190:39719 every 8 connection(s)
I20260812 06:17:28.821247  6093 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81: Bootstrap starting.
I20260812 06:17:28.822211  6093 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:28.823354  6093 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81: No bootstrap required, opened a new log
I20260812 06:17:28.823817  6093 raft_consensus.cc:359] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "94523c017f2a440cbdbe88a409e6bf81" member_type: VOTER }
I20260812 06:17:28.823910  6093 raft_consensus.cc:385] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:28.823971  6093 raft_consensus.cc:740] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 94523c017f2a440cbdbe88a409e6bf81, State: Initialized, Role: FOLLOWER
I20260812 06:17:28.824163  6093 consensus_queue.cc:260] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [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: "94523c017f2a440cbdbe88a409e6bf81" member_type: VOTER }
I20260812 06:17:28.824244  6093 raft_consensus.cc:399] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:28.824288  6093 raft_consensus.cc:493] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:28.824348  6093 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:28.825131  6093 raft_consensus.cc:515] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "94523c017f2a440cbdbe88a409e6bf81" member_type: VOTER }
I20260812 06:17:28.825281  6093 leader_election.cc:304] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [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: 94523c017f2a440cbdbe88a409e6bf81; no voters: 
I20260812 06:17:28.825516  6093 leader_election.cc:290] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:28.825675  6096 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:28.825903  6096 raft_consensus.cc:697] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [term 1 LEADER]: Becoming Leader. State: Replica: 94523c017f2a440cbdbe88a409e6bf81, State: Running, Role: LEADER
I20260812 06:17:28.825989  6093 sys_catalog.cc:565] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:28.826066  6096 consensus_queue.cc:237] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [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: "94523c017f2a440cbdbe88a409e6bf81" member_type: VOTER }
I20260812 06:17:28.826514  6097 sys_catalog.cc:455] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "94523c017f2a440cbdbe88a409e6bf81" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "94523c017f2a440cbdbe88a409e6bf81" member_type: VOTER } }
I20260812 06:17:28.826531  6099 sys_catalog.cc:455] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 94523c017f2a440cbdbe88a409e6bf81. Latest consensus state: current_term: 1 leader_uuid: "94523c017f2a440cbdbe88a409e6bf81" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "94523c017f2a440cbdbe88a409e6bf81" member_type: VOTER } }
I20260812 06:17:28.826625  6097 sys_catalog.cc:458] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:28.826638  6099 sys_catalog.cc:458] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:28.826903  6102 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:28.827739  6102 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:28.827986  5790 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:28.829700  6102 catalog_manager.cc:1383] Generated new cluster ID: dba8e1ea78b2412da9f16f44a86e7249
I20260812 06:17:28.829757  6102 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:28.857502  6102 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:28.858067  6102 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:28.864436  6102 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81: Generated new TSK 0
I20260812 06:17:28.864646  6102 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:28.892776  5790 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:28.894865  6117 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:17:28.894948  6121 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:17:28.894883  6118 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:17:28.895079  5790 server_base.cc:1061] running on GCE node
I20260812 06:17:28.895344  5790 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:28.895392  5790 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:17:28.895407  5790 hybrid_clock.cc:648] HybridClock initialized: now 1786515448895408 us; error 0 us; skew 500 ppm
I20260812 06:17:28.896349  5790 webserver.cc:533] Webserver started at http://127.5.167.129:41245/ using document root <none> and password file <none>
I20260812 06:17:28.896538  5790 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:28.896643  5790 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:28.896721  5790 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:28.897221  5790 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/instance:
uuid: "d9135e02322f43cd9756a766773f8bf5"
format_stamp: "Formatted at 2026-08-12 06:17:28 on dist-test-slave-8n49"
I20260812 06:17:28.898785  5790 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:28.899792  6129 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:17:28.900024  5790 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:28.900115  5790 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root
uuid: "d9135e02322f43cd9756a766773f8bf5"
format_stamp: "Formatted at 2026-08-12 06:17:28 on dist-test-slave-8n49"
I20260812 06:17:28.900203  5790 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-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:17:28.919996  5790 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:28.920425  5790 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:28.920801  5790 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:28.921290  5790 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:28.921348  5790 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:28.921406  5790 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:28.921452  5790 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:28.925886  5790 rpc_server.cc:307] RPC server started. Bound to: 127.5.167.129:39205
I20260812 06:17:28.925916  6203 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.167.129:39205 every 8 connection(s)
I20260812 06:17:28.930861  6204 heartbeater.cc:344] Connected to a master server at 127.5.167.190:39719
I20260812 06:17:28.930989  6204 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:28.931202  6204 heartbeater.cc:507] Master 127.5.167.190:39719 requested a full tablet report, sending...
I20260812 06:17:28.931813  6046 ts_manager.cc:194] Registered new tserver with Master: d9135e02322f43cd9756a766773f8bf5 (127.5.167.129:39205)
I20260812 06:17:28.931972  5790 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.005669152s
I20260812 06:17:28.932664  6046 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45438
I20260812 06:17:28.939142  6046 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45444:
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:17:28.947963  6166 tablet_service.cc:1511] Processing CreateTablet for tablet 33cd24eb0eb14dbeb87464d7aabe4cfa (DEFAULT_TABLE table=heavy-update-compaction-test [id=00fbcfa4f52e436493e2e7fc56d67c36]), partition=
I20260812 06:17:28.948266  6166 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 33cd24eb0eb14dbeb87464d7aabe4cfa. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:28.950323  6222 tablet_bootstrap.cc:492] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Bootstrap starting.
I20260812 06:17:28.951226  6222 tablet_bootstrap.cc:654] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:28.952271  6222 tablet_bootstrap.cc:492] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: No bootstrap required, opened a new log
I20260812 06:17:28.952349  6222 ts_tablet_manager.cc:1403] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:28.952807  6222 raft_consensus.cc:359] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d9135e02322f43cd9756a766773f8bf5" member_type: VOTER last_known_addr { host: "127.5.167.129" port: 39205 } }
I20260812 06:17:28.952899  6222 raft_consensus.cc:385] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:28.952922  6222 raft_consensus.cc:740] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d9135e02322f43cd9756a766773f8bf5, State: Initialized, Role: FOLLOWER
I20260812 06:17:28.953081  6222 consensus_queue.cc:260] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5 [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: "d9135e02322f43cd9756a766773f8bf5" member_type: VOTER last_known_addr { host: "127.5.167.129" port: 39205 } }
I20260812 06:17:28.953176  6222 raft_consensus.cc:399] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:28.953231  6222 raft_consensus.cc:493] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:28.953289  6222 raft_consensus.cc:3060] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:28.954139  6222 raft_consensus.cc:515] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d9135e02322f43cd9756a766773f8bf5" member_type: VOTER last_known_addr { host: "127.5.167.129" port: 39205 } }
I20260812 06:17:28.954259  6222 leader_election.cc:304] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5 [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: d9135e02322f43cd9756a766773f8bf5; no voters: 
I20260812 06:17:28.954421  6222 leader_election.cc:290] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:28.954558  6224 raft_consensus.cc:2804] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:28.954806  6222 ts_tablet_manager.cc:1434] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:28.954839  6204 heartbeater.cc:499] Master 127.5.167.190:39719 was elected leader, sending a full tablet report...
I20260812 06:17:28.954840  6224 raft_consensus.cc:697] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5 [term 1 LEADER]: Becoming Leader. State: Replica: d9135e02322f43cd9756a766773f8bf5, State: Running, Role: LEADER
I20260812 06:17:28.955227  6224 consensus_queue.cc:237] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5 [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: "d9135e02322f43cd9756a766773f8bf5" member_type: VOTER last_known_addr { host: "127.5.167.129" port: 39205 } }
I20260812 06:17:28.956626  6046 catalog_manager.cc:5719] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5 reported cstate change: term changed from 0 to 1, leader changed from <none> to d9135e02322f43cd9756a766773f8bf5 (127.5.167.129). New cstate: current_term: 1 leader_uuid: "d9135e02322f43cd9756a766773f8bf5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d9135e02322f43cd9756a766773f8bf5" member_type: VOTER last_known_addr { host: "127.5.167.129" port: 39205 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:29.020604  5790 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.019s	sys 0.007s
I20260812 06:17:29.176826  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushMRSOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=19.054940
I20260812 06:17:29.332242  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushMRSOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.155s	user 0.114s	sys 0.036s Metrics: {"bytes_written":12430567,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":167,"dirs.run_wall_time_us":773,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40415,"lbm_writes_lt_1ms":770,"mutex_wait_us":182,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1515}
I20260812 06:17:29.333006  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling LogGCOp(33cd24eb0eb14dbeb87464d7aabe4cfa): free 20743880 bytes of WAL
I20260812 06:17:29.333232  6135 log_reader.cc:385] T 33cd24eb0eb14dbeb87464d7aabe4cfa: removed 2 log segments from log reader
I20260812 06:17:29.333274  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000001 (ops 1-6)
I20260812 06:17:29.333333  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000002 (ops 7-11)
I20260812 06:17:29.337442  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: LogGCOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:29.337811  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:29.358327  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.020s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3569333,"delete_count":0,"lbm_write_time_us":5177,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:17:29.358856  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:29.370103  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4067,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.370718  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:29.536666  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.166s	user 0.132s	sys 0.033s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405553,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":610,"lbm_read_time_us":10705,"lbm_reads_lt_1ms":563,"lbm_write_time_us":32373,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":407,"threads_started":5,"update_count":2450}
I20260812 06:17:29.537245  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=11.118625
I20260812 06:17:29.578492  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.041s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":17688,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:29.579041  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:29.607534  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.028s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5278,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:29.607991  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling UndoDeltaBlockGCOp(33cd24eb0eb14dbeb87464d7aabe4cfa): 16821644 bytes on disk
I20260812 06:17:29.608368  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: UndoDeltaBlockGCOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:17:29.608803  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:29.619037  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3956,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.619529  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:29.794665  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.175s	user 0.128s	sys 0.033s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815796,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":610,"lbm_read_time_us":11803,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30033,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:17:29.795195  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=14.095187
I20260812 06:17:29.851263  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.056s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21016,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.851760  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:29.863278  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4008,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.863996  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:30.030813  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.167s	user 0.103s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":298,"lbm_read_time_us":10886,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28018,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":88064,"update_count":2500}
I20260812 06:17:30.031508  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=14.095187
I20260812 06:17:30.094774  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.063s	user 0.040s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21358,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.095292  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:30.107060  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4173,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.107551  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:30.289587  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.182s	user 0.135s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":180,"lbm_read_time_us":11312,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33169,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:17:30.290297  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=14.095187
I20260812 06:17:30.353799  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.063s	user 0.030s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23356,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.354334  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:30.366511  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4335,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.366957  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:30.529445  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.162s	user 0.127s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":226,"lbm_read_time_us":11631,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27069,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:30.530023  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=14.095187
I20260812 06:17:30.594467  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.064s	user 0.029s	sys 0.028s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22209,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.595137  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:30.606274  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4229,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.606765  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushMRSOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:30.650460  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushMRSOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.044s	user 0.028s	sys 0.002s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1468,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1612,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:30.651185  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling LogGCOp(33cd24eb0eb14dbeb87464d7aabe4cfa): free 121006448 bytes of WAL
I20260812 06:17:30.651444  6135 log_reader.cc:385] T 33cd24eb0eb14dbeb87464d7aabe4cfa: removed 12 log segments from log reader
I20260812 06:17:30.651491  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000003 (ops 12-16)
I20260812 06:17:30.651522  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000004 (ops 17-21)
I20260812 06:17:30.651583  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000005 (ops 22-26)
I20260812 06:17:30.651618  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000006 (ops 27-31)
I20260812 06:17:30.651664  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000007 (ops 32-36)
I20260812 06:17:30.651705  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000008 (ops 37-41)
I20260812 06:17:30.651746  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000009 (ops 42-46)
I20260812 06:17:30.651784  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000010 (ops 47-50)
I20260812 06:17:30.651823  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000011 (ops 51-55)
I20260812 06:17:30.651859  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000012 (ops 56-60)
I20260812 06:17:30.651897  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000013 (ops 61-65)
I20260812 06:17:30.651942  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000014 (ops 66-70)
I20260812 06:17:30.678254  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: LogGCOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:30.678717  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling UndoDeltaBlockGCOp(33cd24eb0eb14dbeb87464d7aabe4cfa): 462 bytes on disk
I20260812 06:17:30.679260  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: UndoDeltaBlockGCOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":101,"lbm_reads_lt_1ms":4}
I20260812 06:17:30.679739  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:30.694825  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.015s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4553,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.695300  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:30.706081  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4048,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.706595  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:30.935281  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.228s	user 0.160s	sys 0.064s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020748,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":747,"lbm_read_time_us":15356,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39437,"lbm_writes_lt_1ms":743,"mutex_wait_us":48,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2048,"thread_start_us":129,"threads_started":1,"update_count":3500}
I20260812 06:17:30.935938  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=18.063937
I20260812 06:17:30.991217  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.055s	user 0.017s	sys 0.035s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24223,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:30.991889  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:31.018349  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.026s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5440,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":500}
I20260812 06:17:31.018838  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:31.030172  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4233,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.030848  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:31.209698  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.179s	user 0.147s	sys 0.031s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020629,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":890,"lbm_read_time_us":12760,"lbm_reads_lt_1ms":773,"lbm_write_time_us":37575,"lbm_writes_lt_1ms":743,"mutex_wait_us":269,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":3500}
I20260812 06:17:31.210530  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=14.095187
I20260812 06:17:31.262168  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.051s	user 0.020s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22662,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.262815  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=3.181125
I20260812 06:17:31.278028  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5608,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:31.278528  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:31.287957  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3570,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:31.288604  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:31.454187  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.165s	user 0.120s	sys 0.045s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918204,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1021,"lbm_read_time_us":10704,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33655,"lbm_writes_lt_1ms":643,"mutex_wait_us":303,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":80128,"update_count":3000}
I20260812 06:17:31.454885  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=14.095187
I20260812 06:17:31.514110  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.059s	user 0.022s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":28742,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.514761  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:31.531718  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6759,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.532282  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:31.693181  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.161s	user 0.107s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":418,"lbm_read_time_us":11955,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28283,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:17:31.694905  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=13.103000
I20260812 06:17:31.736620  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.042s	user 0.030s	sys 0.011s Metrics: {"bytes_written":14604842,"delete_count":0,"lbm_write_time_us":17886,"lbm_writes_lt_1ms":359,"reinsert_count":0,"update_count":1780}
I20260812 06:17:31.737317  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:31.748972  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":1805252,"delete_count":0,"lbm_write_time_us":3546,"lbm_writes_lt_1ms":47,"reinsert_count":0,"update_count":220}
I20260812 06:17:31.749497  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:31.915890  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.166s	user 0.106s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713218,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":270,"lbm_read_time_us":11064,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26775,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:17:31.916603  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=11.118625
I20260812 06:17:31.957405  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.040s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":19421,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:31.957990  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:31.980197  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.022s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5638,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:31.980808  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:32.002267  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.021s	user 0.005s	sys 0.015s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.002885  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushMRSOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:32.032717  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushMRSOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.030s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":112,"dirs.run_cpu_time_us":373,"dirs.run_wall_time_us":1572,"drs_written":1,"lbm_read_time_us":109,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2174,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29,"spinlock_wait_cycles":25472}
I20260812 06:17:32.033533  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling UndoDeltaBlockGCOp(33cd24eb0eb14dbeb87464d7aabe4cfa): 461 bytes on disk
I20260812 06:17:32.034037  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: UndoDeltaBlockGCOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:17:32.034734  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:32.213876  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.179s	user 0.119s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":189,"lbm_read_time_us":10677,"lbm_reads_lt_1ms":565,"lbm_write_time_us":31520,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:32.214484  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling LogGCOp(33cd24eb0eb14dbeb87464d7aabe4cfa): free 124257201 bytes of WAL
I20260812 06:17:32.214917  6135 log_reader.cc:385] T 33cd24eb0eb14dbeb87464d7aabe4cfa: removed 12 log segments from log reader
I20260812 06:17:32.214993  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000015 (ops 71-74)
I20260812 06:17:32.215082  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000016 (ops 75-79)
I20260812 06:17:32.215152  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000017 (ops 80-84)
I20260812 06:17:32.215198  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000018 (ops 85-89)
I20260812 06:17:32.215242  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000019 (ops 90-94)
I20260812 06:17:32.215284  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000020 (ops 95-99)
I20260812 06:17:32.215327  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000021 (ops 100-104)
I20260812 06:17:32.215369  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000022 (ops 105-109)
I20260812 06:17:32.215440  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000023 (ops 110-114)
I20260812 06:17:32.215505  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000024 (ops 115-119)
I20260812 06:17:32.215553  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000025 (ops 120-124)
I20260812 06:17:32.215596  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000026 (ops 125-129)
I20260812 06:17:32.243533  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: LogGCOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:32.244005  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=14.095187
I20260812 06:17:32.291654  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.047s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21082,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.292145  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:32.324978  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.033s	user 0.009s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4628,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.325524  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:32.337033  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4346,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.337502  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:32.542158  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.204s	user 0.140s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918212,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1479,"lbm_read_time_us":14071,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34982,"lbm_writes_lt_1ms":643,"mutex_wait_us":396,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":3000}
I20260812 06:17:32.542696  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=14.095187
I20260812 06:17:32.599900  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.057s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19842,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.600651  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:32.612067  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4492,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.612658  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:32.788938  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.176s	user 0.097s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":898,"lbm_read_time_us":12907,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26749,"lbm_writes_lt_1ms":543,"mutex_wait_us":271,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:17:32.789676  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=14.095187
I20260812 06:17:32.846529  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.057s	user 0.038s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23289,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.847179  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:32.866812  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.019s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3975,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.867566  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:33.049497  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.182s	user 0.094s	sys 0.084s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":385,"lbm_read_time_us":10694,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30051,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2500}
I20260812 06:17:33.050256  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=14.095187
I20260812 06:17:33.100937  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.051s	user 0.031s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22751,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.101528  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:33.113683  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4105,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.114276  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:33.290771  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.176s	user 0.112s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":260,"lbm_read_time_us":10081,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28616,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":132096,"update_count":2500}
I20260812 06:17:33.291352  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=14.095187
I20260812 06:17:33.340444  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.049s	user 0.036s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20371,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.341059  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:33.356689  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.015s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5841,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.357203  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:33.520749  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.163s	user 0.132s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":546,"lbm_read_time_us":11611,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32685,"lbm_writes_lt_1ms":543,"mutex_wait_us":5,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:33.521298  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=11.118625
I20260812 06:17:33.573071  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.052s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19944,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:33.573745  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:33.585050  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4029,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.585513  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:33.595283  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3608,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.595755  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushMRSOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:33.630697  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushMRSOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.035s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1308,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2006,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:33.631426  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling LogGCOp(33cd24eb0eb14dbeb87464d7aabe4cfa): free 124257560 bytes of WAL
I20260812 06:17:33.631670  6135 log_reader.cc:385] T 33cd24eb0eb14dbeb87464d7aabe4cfa: removed 12 log segments from log reader
I20260812 06:17:33.631714  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000027 (ops 130-134)
I20260812 06:17:33.631743  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000028 (ops 135-138)
I20260812 06:17:33.631810  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000029 (ops 139-143)
I20260812 06:17:33.631855  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000030 (ops 144-148)
I20260812 06:17:33.631896  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000031 (ops 149-153)
I20260812 06:17:33.631953  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000032 (ops 154-158)
I20260812 06:17:33.631994  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000033 (ops 159-163)
I20260812 06:17:33.632036  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000034 (ops 164-168)
I20260812 06:17:33.632077  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000035 (ops 169-173)
I20260812 06:17:33.632117  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000036 (ops 174-178)
I20260812 06:17:33.632155  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000037 (ops 179-183)
I20260812 06:17:33.632194  6135 log.cc:1079] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: Deleting log segment in path: /tmp/dist-test-taskaYM8FZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443134132-5790-0/minicluster-data/ts-0-root/wals/33cd24eb0eb14dbeb87464d7aabe4cfa/wal-000000038 (ops 184-188)
I20260812 06:17:33.660179  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: LogGCOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:33.660697  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=3.181125
I20260812 06:17:33.680986  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.020s	user 0.012s	sys 0.005s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":6892,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:33.681527  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling UndoDeltaBlockGCOp(33cd24eb0eb14dbeb87464d7aabe4cfa): 482 bytes on disk
I20260812 06:17:33.681919  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: UndoDeltaBlockGCOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:17:33.682427  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=2.188937
I20260812 06:17:33.704157  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.022s	user 0.000s	sys 0.018s 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:17:33.704814  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=1.000000
I20260812 06:17:33.898757  5790 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.878s	user 1.813s	sys 0.156s
I20260812 06:17:33.940163  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: MajorDeltaCompactionOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.235s	user 0.149s	sys 0.084s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020844,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"lbm_read_time_us":17785,"lbm_reads_lt_1ms":771,"lbm_write_time_us":38896,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:17:33.940788  6205 maintenance_manager.cc:419] P d9135e02322f43cd9756a766773f8bf5: Scheduling FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa): perf score=14.095187
I20260812 06:17:33.982535  5790 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.083s	user 0.001s	sys 0.000s
I20260812 06:17:33.983086  5790 tablet_server.cc:179] TabletServer@127.5.167.129:0 shutting down...
I20260812 06:17:34.027324  6135 maintenance_manager.cc:643] P d9135e02322f43cd9756a766773f8bf5: FlushDeltaMemStoresOp(33cd24eb0eb14dbeb87464d7aabe4cfa) complete. Timing: real 0.086s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16478,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.027997  5790 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:34.028228  5790 tablet_replica.cc:333] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5: stopping tablet replica
I20260812 06:17:34.028407  5790 raft_consensus.cc:2243] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:34.028685  5790 raft_consensus.cc:2272] T 33cd24eb0eb14dbeb87464d7aabe4cfa P d9135e02322f43cd9756a766773f8bf5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:34.042400  5790 tablet_server.cc:196] TabletServer@127.5.167.129:0 shutdown complete.
I20260812 06:17:34.045449  5790 master.cc:562] Master@127.5.167.190:39719 shutting down...
I20260812 06:17:34.049432  5790 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:34.049606  5790 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:34.049659  5790 tablet_replica.cc:333] T 00000000000000000000000000000000 P 94523c017f2a440cbdbe88a409e6bf81: stopping tablet replica
I20260812 06:17:34.062211  5790 master.cc:584] Master@127.5.167.190:39719 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5382 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11003 ms total)

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