[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:32.911899 32190 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.31.111.190:35085
I20260812 06:19:32.912945 32190 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:32.913615 32190 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:32.920259 32195 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:32.920343 32190 server_base.cc:1061] running on GCE node
W20260812 06:19:32.920348 32197 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:32.920656 32201 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:32.921231 32190 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:32.921356 32190 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:32.921417 32190 hybrid_clock.cc:648] HybridClock initialized: now 1786515572921414 us; error 0 us; skew 500 ppm
I20260812 06:19:32.923311 32190 webserver.cc:533] Webserver started at http://127.31.111.190:41807/ using document root <none> and password file <none>
I20260812 06:19:32.923895 32190 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:32.923985 32190 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:32.924235 32190 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:32.926002 32190 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/master-0-root/instance:
uuid: "11fe7f3798264f8cbebccb2ea28109e9"
format_stamp: "Formatted at 2026-08-12 06:19:32 on dist-test-slave-gsp7"
I20260812 06:19:32.929572 32190 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:32.931679 32210 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:32.932677 32190 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:32.932813 32190 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/master-0-root
uuid: "11fe7f3798264f8cbebccb2ea28109e9"
format_stamp: "Formatted at 2026-08-12 06:19:32 on dist-test-slave-gsp7"
I20260812 06:19:32.932924 32190 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:32.951256 32190 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:32.951962 32190 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:32.952157 32190 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:32.960772 32190 rpc_server.cc:307] RPC server started. Bound to: 127.31.111.190:35085
I20260812 06:19:32.960795 32289 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.111.190:35085 every 8 connection(s)
I20260812 06:19:32.963686 32291 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:32.972713 32291 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9: Bootstrap starting.
I20260812 06:19:32.976341 32291 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:32.977766 32291 log.cc:826] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:32.980230 32291 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9: No bootstrap required, opened a new log
I20260812 06:19:32.985293 32291 raft_consensus.cc:359] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "11fe7f3798264f8cbebccb2ea28109e9" member_type: VOTER }
I20260812 06:19:32.985643 32291 raft_consensus.cc:385] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:32.985775 32291 raft_consensus.cc:740] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 11fe7f3798264f8cbebccb2ea28109e9, State: Initialized, Role: FOLLOWER
I20260812 06:19:32.986636 32291 consensus_queue.cc:260] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [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: "11fe7f3798264f8cbebccb2ea28109e9" member_type: VOTER }
I20260812 06:19:32.986900 32291 raft_consensus.cc:399] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:32.987025 32291 raft_consensus.cc:493] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:32.987197 32291 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:32.988492 32291 raft_consensus.cc:515] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "11fe7f3798264f8cbebccb2ea28109e9" member_type: VOTER }
I20260812 06:19:32.989094 32291 leader_election.cc:304] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [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: 11fe7f3798264f8cbebccb2ea28109e9; no voters: 
I20260812 06:19:32.989527 32291 leader_election.cc:290] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:32.989707 32296 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:32.990013 32296 raft_consensus.cc:697] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [term 1 LEADER]: Becoming Leader. State: Replica: 11fe7f3798264f8cbebccb2ea28109e9, State: Running, Role: LEADER
I20260812 06:19:32.990475 32296 consensus_queue.cc:237] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [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: "11fe7f3798264f8cbebccb2ea28109e9" member_type: VOTER }
I20260812 06:19:32.990819 32291 sys_catalog.cc:565] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:32.992357 32298 sys_catalog.cc:455] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 11fe7f3798264f8cbebccb2ea28109e9. Latest consensus state: current_term: 1 leader_uuid: "11fe7f3798264f8cbebccb2ea28109e9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "11fe7f3798264f8cbebccb2ea28109e9" member_type: VOTER } }
I20260812 06:19:32.992479 32298 sys_catalog.cc:458] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:32.992820 32297 sys_catalog.cc:455] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "11fe7f3798264f8cbebccb2ea28109e9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "11fe7f3798264f8cbebccb2ea28109e9" member_type: VOTER } }
I20260812 06:19:32.992854 32312 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:32.992894 32297 sys_catalog.cc:458] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:32.995565 32312 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:32.995939 32190 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:33.000780 32312 catalog_manager.cc:1383] Generated new cluster ID: e89fd62eed47452cb779aabd569e33cc
I20260812 06:19:33.000943 32312 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:33.024931 32312 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:33.026177 32312 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:33.038714 32312 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9: Generated new TSK 0
I20260812 06:19:33.039568 32312 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:33.061321 32190 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:33.064654 32335 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:33.064929 32333 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:33.064661 32331 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:33.065109 32190 server_base.cc:1061] running on GCE node
I20260812 06:19:33.065402 32190 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:33.065460 32190 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:33.065506 32190 hybrid_clock.cc:648] HybridClock initialized: now 1786515573065506 us; error 0 us; skew 500 ppm
I20260812 06:19:33.066553 32190 webserver.cc:533] Webserver started at http://127.31.111.129:41915/ using document root <none> and password file <none>
I20260812 06:19:33.066723 32190 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:33.066782 32190 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:33.066861 32190 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:33.067301 32190 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/instance:
uuid: "68b1ecc72e6d483cbb174537e95e07db"
format_stamp: "Formatted at 2026-08-12 06:19:33 on dist-test-slave-gsp7"
I20260812 06:19:33.069233 32190 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:33.070453 32342 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:33.070726 32190 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:33.070804 32190 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root
uuid: "68b1ecc72e6d483cbb174537e95e07db"
format_stamp: "Formatted at 2026-08-12 06:19:33 on dist-test-slave-gsp7"
I20260812 06:19:33.070883 32190 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:33.104401 32190 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:33.105337 32190 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:33.105962 32190 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:33.107023 32190 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:33.107091 32190 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:33.107149 32190 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:33.107182 32190 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:33.114037 32190 rpc_server.cc:307] RPC server started. Bound to: 127.31.111.129:37045
I20260812 06:19:33.114118 32452 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.111.129:37045 every 8 connection(s)
I20260812 06:19:33.126930 32453 heartbeater.cc:344] Connected to a master server at 127.31.111.190:35085
I20260812 06:19:33.127208 32453 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:33.127718 32453 heartbeater.cc:507] Master 127.31.111.190:35085 requested a full tablet report, sending...
I20260812 06:19:33.129129 32242 ts_manager.cc:194] Registered new tserver with Master: 68b1ecc72e6d483cbb174537e95e07db (127.31.111.129:37045)
I20260812 06:19:33.129367 32190 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014640422s
I20260812 06:19:33.130733 32242 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51148
I20260812 06:19:33.139472 32242 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51150:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:33.154661 32392 tablet_service.cc:1511] Processing CreateTablet for tablet cd84b2827c0341f99f60ffd4fcd0b2cc (DEFAULT_TABLE table=heavy-update-compaction-test [id=7cbb8c7490154bd1a7243a2954de8402]), partition=
I20260812 06:19:33.155175 32392 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cd84b2827c0341f99f60ffd4fcd0b2cc. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:33.158222 32467 tablet_bootstrap.cc:492] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Bootstrap starting.
I20260812 06:19:33.159281 32467 tablet_bootstrap.cc:654] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:33.160789 32467 tablet_bootstrap.cc:492] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: No bootstrap required, opened a new log
I20260812 06:19:33.160881 32467 ts_tablet_manager.cc:1403] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:33.161398 32467 raft_consensus.cc:359] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "68b1ecc72e6d483cbb174537e95e07db" member_type: VOTER last_known_addr { host: "127.31.111.129" port: 37045 } }
I20260812 06:19:33.161571 32467 raft_consensus.cc:385] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:33.161618 32467 raft_consensus.cc:740] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 68b1ecc72e6d483cbb174537e95e07db, State: Initialized, Role: FOLLOWER
I20260812 06:19:33.161815 32467 consensus_queue.cc:260] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db [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: "68b1ecc72e6d483cbb174537e95e07db" member_type: VOTER last_known_addr { host: "127.31.111.129" port: 37045 } }
I20260812 06:19:33.161923 32467 raft_consensus.cc:399] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:33.162019 32467 raft_consensus.cc:493] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:33.162130 32467 raft_consensus.cc:3060] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:33.163058 32467 raft_consensus.cc:515] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "68b1ecc72e6d483cbb174537e95e07db" member_type: VOTER last_known_addr { host: "127.31.111.129" port: 37045 } }
I20260812 06:19:33.163228 32467 leader_election.cc:304] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db [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: 68b1ecc72e6d483cbb174537e95e07db; no voters: 
I20260812 06:19:33.163473 32467 leader_election.cc:290] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:33.163586 32471 raft_consensus.cc:2804] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:33.163836 32471 raft_consensus.cc:697] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db [term 1 LEADER]: Becoming Leader. State: Replica: 68b1ecc72e6d483cbb174537e95e07db, State: Running, Role: LEADER
I20260812 06:19:33.163861 32467 ts_tablet_manager.cc:1434] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:33.164072 32453 heartbeater.cc:499] Master 127.31.111.190:35085 was elected leader, sending a full tablet report...
I20260812 06:19:33.164249 32471 consensus_queue.cc:237] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db [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: "68b1ecc72e6d483cbb174537e95e07db" member_type: VOTER last_known_addr { host: "127.31.111.129" port: 37045 } }
I20260812 06:19:33.167423 32242 catalog_manager.cc:5719] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db reported cstate change: term changed from 0 to 1, leader changed from <none> to 68b1ecc72e6d483cbb174537e95e07db (127.31.111.129). New cstate: current_term: 1 leader_uuid: "68b1ecc72e6d483cbb174537e95e07db" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "68b1ecc72e6d483cbb174537e95e07db" member_type: VOTER last_known_addr { host: "127.31.111.129" port: 37045 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:33.233593 32190 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.018s	sys 0.012s
I20260812 06:19:33.365383 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushMRSOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=19.054940
I20260812 06:19:33.544919 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushMRSOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.179s	user 0.130s	sys 0.045s Metrics: {"bytes_written":12635684,"cfile_init":1,"compiler_manager_pool.queue_time_us":213,"delete_count":0,"dirs.queue_time_us":108,"dirs.run_cpu_time_us":263,"dirs.run_wall_time_us":1133,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44405,"lbm_writes_lt_1ms":765,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":300288,"thread_start_us":140,"threads_started":1,"update_count":1540}
I20260812 06:19:33.546186 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling LogGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc): free 20743880 bytes of WAL
I20260812 06:19:33.546519 32349 log_reader.cc:385] T cd84b2827c0341f99f60ffd4fcd0b2cc: removed 2 log segments from log reader
I20260812 06:19:33.546591 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000001 (ops 1-6)
I20260812 06:19:33.546645 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000002 (ops 7-11)
I20260812 06:19:33.552083 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: LogGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:33.552598 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:33.575024 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.022s	user 0.015s	sys 0.002s Metrics: {"bytes_written":4020613,"delete_count":0,"lbm_write_time_us":4077,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:19:33.575567 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:33.590307 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3856508,"delete_count":0,"lbm_write_time_us":5563,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:19:33.590981 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:33.768011 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.177s	user 0.136s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774805,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":882,"lbm_read_time_us":13725,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26985,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"thread_start_us":341,"threads_started":5,"update_count":2500}
I20260812 06:19:33.768698 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=10.126437
I20260812 06:19:33.806151 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.037s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15564,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.806625 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:33.819532 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4919,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.820218 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling UndoDeltaBlockGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc): 16411394 bytes on disk
I20260812 06:19:33.821609 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: UndoDeltaBlockGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":109,"lbm_reads_lt_1ms":4}
I20260812 06:19:33.822307 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:33.948155 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.126s	user 0.106s	sys 0.016s 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":1301,"lbm_read_time_us":8566,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23129,"lbm_writes_lt_1ms":443,"mutex_wait_us":300,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:19:33.949721 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=10.126437
I20260812 06:19:33.985158 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.035s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15671,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.985755 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:34.001794 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6397,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.002265 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:34.129153 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.127s	user 0.102s	sys 0.024s 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":332,"lbm_read_time_us":8072,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24752,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":96128,"update_count":2000}
I20260812 06:19:34.129882 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=10.126437
I20260812 06:19:34.172317 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.042s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17554,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.172904 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:34.184091 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4110,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.184906 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:34.309023 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.124s	user 0.100s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":609,"lbm_read_time_us":7687,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25008,"lbm_writes_lt_1ms":443,"mutex_wait_us":282,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:19:34.309741 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=10.126437
I20260812 06:19:34.356305 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.046s	user 0.025s	sys 0.016s Metrics: {"bytes_written":12307496,"delete_count":0,"lbm_write_time_us":15112,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.357036 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:34.367995 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.368475 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:34.531522 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.163s	user 0.126s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672283,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":366,"lbm_read_time_us":12751,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27170,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2000}
I20260812 06:19:34.532114 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=10.126437
I20260812 06:19:34.566471 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.034s	user 0.020s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13993,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.567080 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:34.676546 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.109s	user 0.075s	sys 0.032s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":725,"lbm_read_time_us":6464,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20032,"lbm_writes_lt_1ms":343,"mutex_wait_us":45,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":32000,"update_count":1500}
I20260812 06:19:34.677073 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=10.126437
I20260812 06:19:34.722472 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.045s	user 0.025s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14269,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.723115 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:34.738648 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5827,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.739137 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushMRSOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:34.777278 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushMRSOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.038s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":1172,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1724,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:34.778182 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling LogGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc): free 112239270 bytes of WAL
I20260812 06:19:34.778432 32349 log_reader.cc:385] T cd84b2827c0341f99f60ffd4fcd0b2cc: removed 11 log segments from log reader
I20260812 06:19:34.778484 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000003 (ops 12-16)
I20260812 06:19:34.778513 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000004 (ops 17-20)
I20260812 06:19:34.778587 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000005 (ops 21-25)
I20260812 06:19:34.778630 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000006 (ops 26-30)
I20260812 06:19:34.778672 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000007 (ops 31-35)
I20260812 06:19:34.778702 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000008 (ops 36-40)
I20260812 06:19:34.778738 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000009 (ops 41-45)
I20260812 06:19:34.778775 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000010 (ops 46-50)
I20260812 06:19:34.778815 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000011 (ops 51-55)
I20260812 06:19:34.778853 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000012 (ops 56-60)
I20260812 06:19:34.778893 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000013 (ops 61-65)
I20260812 06:19:34.802208 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: LogGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:34.802646 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:34.818594 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.016s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5384,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.819041 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling UndoDeltaBlockGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc): 447 bytes on disk
I20260812 06:19:34.819491 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: UndoDeltaBlockGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:34.819919 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:34.830343 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3911,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.830969 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:35.015683 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.185s	user 0.118s	sys 0.058s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2624,"lbm_read_time_us":12076,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34115,"lbm_writes_lt_1ms":643,"mutex_wait_us":2079,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20864,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:19:35.016330 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=14.095187
I20260812 06:19:35.068066 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.052s	user 0.032s	sys 0.015s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21920,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.068630 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:35.081318 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4170,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.081863 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:35.232110 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.149s	user 0.121s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":954,"lbm_read_time_us":11118,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29167,"lbm_writes_lt_1ms":543,"mutex_wait_us":267,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:19:35.232846 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=11.118625
I20260812 06:19:35.294271 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.061s	user 0.022s	sys 0.016s Metrics: {"bytes_written":13045918,"delete_count":0,"lbm_write_time_us":17049,"lbm_writes_lt_1ms":321,"reinsert_count":0,"update_count":1590}
I20260812 06:19:35.294754 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:35.307786 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.013s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3774460,"delete_count":0,"lbm_write_time_us":3599,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:19:35.308418 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:35.318233 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3558,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:35.318866 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:35.489111 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.170s	user 0.127s	sys 0.032s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774783,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1021,"lbm_read_time_us":11001,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30056,"lbm_writes_lt_1ms":543,"mutex_wait_us":304,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2500}
I20260812 06:19:35.489744 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=14.095187
I20260812 06:19:35.535247 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.045s	user 0.024s	sys 0.017s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":18793,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.535714 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:35.692648 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.157s	user 0.116s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672155,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":457,"lbm_read_time_us":9743,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26438,"lbm_writes_lt_1ms":443,"mutex_wait_us":71,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":292992,"update_count":2000}
I20260812 06:19:35.693120 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=14.095187
I20260812 06:19:35.756767 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.063s	user 0.035s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26308,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.757395 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:35.775655 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.018s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6776,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.776209 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:35.966621 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.190s	user 0.129s	sys 0.053s 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":781,"lbm_read_time_us":14379,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29394,"lbm_writes_lt_1ms":543,"mutex_wait_us":92,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:19:35.967397 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=14.095187
I20260812 06:19:36.020944 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.053s	user 0.034s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23537,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.021596 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:36.033114 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4256,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.033741 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:36.184540 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.151s	user 0.110s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":156,"lbm_read_time_us":11004,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29723,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":2500}
I20260812 06:19:36.185247 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=11.118625
I20260812 06:19:36.230134 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.045s	user 0.034s	sys 0.008s Metrics: {"bytes_written":12717740,"delete_count":0,"lbm_write_time_us":16894,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:36.230792 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:36.247174 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4143686,"delete_count":0,"lbm_write_time_us":6599,"lbm_writes_lt_1ms":104,"reinsert_count":0,"update_count":505}
I20260812 06:19:36.247668 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:36.257202 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":3606,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:19:36.257731 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushMRSOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:36.291687 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushMRSOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":1205,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1996,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:36.292485 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling LogGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc): free 124710306 bytes of WAL
I20260812 06:19:36.292814 32349 log_reader.cc:385] T cd84b2827c0341f99f60ffd4fcd0b2cc: removed 12 log segments from log reader
I20260812 06:19:36.292899 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000014 (ops 66-70)
I20260812 06:19:36.292939 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000015 (ops 71-75)
I20260812 06:19:36.292977 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000016 (ops 76-80)
I20260812 06:19:36.293005 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000017 (ops 81-85)
I20260812 06:19:36.293036 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000018 (ops 86-90)
I20260812 06:19:36.293058 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000019 (ops 91-95)
I20260812 06:19:36.293082 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000020 (ops 96-100)
I20260812 06:19:36.293112 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000021 (ops 101-105)
I20260812 06:19:36.293146 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000022 (ops 106-110)
I20260812 06:19:36.293179 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000023 (ops 111-115)
I20260812 06:19:36.293207 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000024 (ops 116-120)
I20260812 06:19:36.293236 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000025 (ops 121-125)
I20260812 06:19:36.324085 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: LogGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:36.324568 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=3.181125
I20260812 06:19:36.354090 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.029s	user 0.007s	sys 0.019s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":7288,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:36.354694 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling LogGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc): free 12017995 bytes of WAL
I20260812 06:19:36.354939 32349 log_reader.cc:385] T cd84b2827c0341f99f60ffd4fcd0b2cc: removed 1 log segments from log reader
I20260812 06:19:36.355002 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000026 (ops 126-130)
I20260812 06:19:36.357579 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: LogGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:36.357932 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:36.367723 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.010s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3612,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:36.368184 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:36.586807 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.218s	user 0.150s	sys 0.068s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979854,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":789,"lbm_read_time_us":17947,"lbm_reads_lt_1ms":775,"lbm_write_time_us":35240,"lbm_writes_lt_1ms":743,"mutex_wait_us":315,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:19:36.587347 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=14.095187
I20260812 06:19:36.650478 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.063s	user 0.026s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22907,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.651093 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling UndoDeltaBlockGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc): 482 bytes on disk
I20260812 06:19:36.651583 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: UndoDeltaBlockGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:19:36.652122 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:36.663379 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4305,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.663868 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:36.835225 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.171s	user 0.111s	sys 0.054s 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":158,"lbm_read_time_us":12973,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28946,"lbm_writes_lt_1ms":543,"mutex_wait_us":77,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2500}
I20260812 06:19:36.835770 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=11.118625
I20260812 06:19:36.873174 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.037s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16427,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:36.873941 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:36.894723 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.021s	user 0.009s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5706,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:36.895351 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:37.046458 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.151s	user 0.112s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":321,"lbm_read_time_us":9971,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26964,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:19:37.047151 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=11.118625
I20260812 06:19:37.087524 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.040s	user 0.010s	sys 0.028s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18202,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:37.088192 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:37.101456 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5136,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:37.102111 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:37.240170 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.138s	user 0.101s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":968,"lbm_read_time_us":9474,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29125,"lbm_writes_lt_1ms":443,"mutex_wait_us":276,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:19:37.240831 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=11.118625
I20260812 06:19:37.283294 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.042s	user 0.029s	sys 0.011s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":18833,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:37.283784 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:37.295569 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4544,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:37.296109 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:37.424043 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.128s	user 0.111s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":487,"lbm_read_time_us":9969,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24291,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2000}
I20260812 06:19:37.424813 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=10.126437
I20260812 06:19:37.473083 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.048s	user 0.020s	sys 0.022s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15824,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.473779 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:37.484835 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4201,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.485332 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:37.631690 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.146s	user 0.094s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":146,"lbm_read_time_us":11441,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23041,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2000}
I20260812 06:19:37.634697 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=10.126437
I20260812 06:19:37.681264 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.046s	user 0.019s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20745,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.681895 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:37.698902 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.017s	user 0.010s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6645,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.699545 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:37.919904 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.220s	user 0.186s	sys 0.021s 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":1740,"lbm_read_time_us":12660,"lbm_reads_lt_1ms":472,"lbm_write_time_us":34982,"lbm_writes_lt_1ms":443,"mutex_wait_us":644,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:37.920670 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=18.063937
I20260812 06:19:37.988925 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.068s	user 0.040s	sys 0.024s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":31530,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:37.989470 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:38.000797 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4368,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.001328 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushMRSOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:38.042440 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushMRSOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.041s	user 0.038s	sys 0.001s Metrics: {"bytes_written":1357582,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":2713,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2435,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:19:38.043215 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling LogGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc): free 129773837 bytes of WAL
I20260812 06:19:38.043442 32349 log_reader.cc:385] T cd84b2827c0341f99f60ffd4fcd0b2cc: removed 13 log segments from log reader
I20260812 06:19:38.043493 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000027 (ops 131-135)
I20260812 06:19:38.043531 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000028 (ops 136-140)
I20260812 06:19:38.043563 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000029 (ops 141-145)
I20260812 06:19:38.043645 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000030 (ops 146-150)
I20260812 06:19:38.043689 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000031 (ops 151-154)
I20260812 06:19:38.043713 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000032 (ops 155-159)
I20260812 06:19:38.043771 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000033 (ops 160-164)
I20260812 06:19:38.043807 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000034 (ops 165-169)
I20260812 06:19:38.043835 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000035 (ops 170-174)
I20260812 06:19:38.043867 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000036 (ops 175-179)
I20260812 06:19:38.043926 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000037 (ops 180-184)
I20260812 06:19:38.043962 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000038 (ops 185-189)
I20260812 06:19:38.044023 32349 log.cc:1079] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/cd84b2827c0341f99f60ffd4fcd0b2cc/wal-000000039 (ops 190-194)
I20260812 06:19:38.078547 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: LogGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.035s	user 0.000s	sys 0.034s Metrics: {}
I20260812 06:19:38.079030 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling UndoDeltaBlockGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc): 507 bytes on disk
I20260812 06:19:38.079519 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: UndoDeltaBlockGCOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:19:38.080387 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:38.105825 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.025s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5001,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":500}
I20260812 06:19:38.106462 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=2.188937
I20260812 06:19:38.125814 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: FlushDeltaMemStoresOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.019s	user 0.011s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7032,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.126483 32454 maintenance_manager.cc:419] P 68b1ecc72e6d483cbb174537e95e07db: Scheduling MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc): perf score=1.000000
I20260812 06:19:38.217689 32190 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.984s	user 1.838s	sys 0.163s
I20260812 06:19:38.334810 32190 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.117s	user 0.002s	sys 0.000s
I20260812 06:19:38.335491 32190 tablet_server.cc:179] TabletServer@127.31.111.129:0 shutting down...
I20260812 06:19:38.387912 32349 maintenance_manager.cc:643] P 68b1ecc72e6d483cbb174537e95e07db: MajorDeltaCompactionOp(cd84b2827c0341f99f60ffd4fcd0b2cc) complete. Timing: real 0.261s	user 0.180s	sys 0.072s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082166,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":851,"lbm_read_time_us":27319,"lbm_reads_lt_1ms":870,"lbm_write_time_us":39188,"lbm_writes_lt_1ms":843,"mutex_wait_us":25,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":25984,"thread_start_us":76,"threads_started":1,"update_count":4000}
I20260812 06:19:38.389055 32190 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:38.389683 32190 tablet_replica.cc:333] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db: stopping tablet replica
I20260812 06:19:38.389941 32190 raft_consensus.cc:2243] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:38.390205 32190 raft_consensus.cc:2272] T cd84b2827c0341f99f60ffd4fcd0b2cc P 68b1ecc72e6d483cbb174537e95e07db [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:38.409060 32190 tablet_server.cc:196] TabletServer@127.31.111.129:0 shutdown complete.
I20260812 06:19:38.461594 32190 master.cc:562] Master@127.31.111.190:35085 shutting down...
I20260812 06:19:38.465526 32190 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:38.465756 32190 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:38.465858 32190 tablet_replica.cc:333] T 00000000000000000000000000000000 P 11fe7f3798264f8cbebccb2ea28109e9: stopping tablet replica
I20260812 06:19:38.478493 32190 master.cc:584] Master@127.31.111.190:35085 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5653 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:38.579213 32190 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.31.111.190:39963
I20260812 06:19:38.579665 32190 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:38.581888 32503 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:38.581905 32190 server_base.cc:1061] running on GCE node
W20260812 06:19:38.581911 32500 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:38.581888 32499 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:38.582361 32190 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:38.582405 32190 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:38.582420 32190 hybrid_clock.cc:648] HybridClock initialized: now 1786515578582420 us; error 0 us; skew 500 ppm
I20260812 06:19:38.583251 32190 webserver.cc:533] Webserver started at http://127.31.111.190:46301/ using document root <none> and password file <none>
I20260812 06:19:38.583387 32190 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:38.583431 32190 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:38.583503 32190 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:38.583921 32190 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/master-0-root/instance:
uuid: "77919babe78949838434742a7fa8fc59"
format_stamp: "Formatted at 2026-08-12 06:19:38 on dist-test-slave-gsp7"
I20260812 06:19:38.585397 32190 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:38.586413 32518 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:38.586674 32190 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:38.586766 32190 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/master-0-root
uuid: "77919babe78949838434742a7fa8fc59"
format_stamp: "Formatted at 2026-08-12 06:19:38 on dist-test-slave-gsp7"
I20260812 06:19:38.586858 32190 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:38.611457 32190 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:38.611919 32190 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:38.616381 32190 rpc_server.cc:307] RPC server started. Bound to: 127.31.111.190:39963
I20260812 06:19:38.624836 32607 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.111.190:39963 every 8 connection(s)
I20260812 06:19:38.625370 32608 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:38.627283 32608 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59: Bootstrap starting.
I20260812 06:19:38.628153 32608 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:38.629242 32608 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59: No bootstrap required, opened a new log
I20260812 06:19:38.629693 32608 raft_consensus.cc:359] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "77919babe78949838434742a7fa8fc59" member_type: VOTER }
I20260812 06:19:38.629784 32608 raft_consensus.cc:385] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:38.629832 32608 raft_consensus.cc:740] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 77919babe78949838434742a7fa8fc59, State: Initialized, Role: FOLLOWER
I20260812 06:19:38.630031 32608 consensus_queue.cc:260] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [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: "77919babe78949838434742a7fa8fc59" member_type: VOTER }
I20260812 06:19:38.630107 32608 raft_consensus.cc:399] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:38.630132 32608 raft_consensus.cc:493] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:38.630211 32608 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:38.630934 32608 raft_consensus.cc:515] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "77919babe78949838434742a7fa8fc59" member_type: VOTER }
I20260812 06:19:38.631085 32608 leader_election.cc:304] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [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: 77919babe78949838434742a7fa8fc59; no voters: 
I20260812 06:19:38.631313 32608 leader_election.cc:290] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:38.631465 32611 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:38.631716 32611 raft_consensus.cc:697] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [term 1 LEADER]: Becoming Leader. State: Replica: 77919babe78949838434742a7fa8fc59, State: Running, Role: LEADER
I20260812 06:19:38.631794 32608 sys_catalog.cc:565] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:38.631901 32611 consensus_queue.cc:237] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [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: "77919babe78949838434742a7fa8fc59" member_type: VOTER }
I20260812 06:19:38.632364 32613 sys_catalog.cc:455] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "77919babe78949838434742a7fa8fc59" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "77919babe78949838434742a7fa8fc59" member_type: VOTER } }
I20260812 06:19:38.632494 32613 sys_catalog.cc:458] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:38.633064 32614 sys_catalog.cc:455] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 77919babe78949838434742a7fa8fc59. Latest consensus state: current_term: 1 leader_uuid: "77919babe78949838434742a7fa8fc59" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "77919babe78949838434742a7fa8fc59" member_type: VOTER } }
I20260812 06:19:38.633162 32614 sys_catalog.cc:458] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:38.633446 32618 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:38.634212 32618 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:38.634414 32190 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:38.636202 32618 catalog_manager.cc:1383] Generated new cluster ID: cd841433e01341babf90d9095106c0a9
I20260812 06:19:38.636268 32618 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:38.659039 32618 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:38.659742 32618 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:38.667596 32618 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59: Generated new TSK 0
I20260812 06:19:38.667833 32618 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:38.699627 32190 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:38.701689 32639 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:38.701689 32649 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:38.701898 32637 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:38.701830 32190 server_base.cc:1061] running on GCE node
I20260812 06:19:38.702096 32190 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:38.702140 32190 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:38.702165 32190 hybrid_clock.cc:648] HybridClock initialized: now 1786515578702165 us; error 0 us; skew 500 ppm
I20260812 06:19:38.703024 32190 webserver.cc:533] Webserver started at http://127.31.111.129:33049/ using document root <none> and password file <none>
I20260812 06:19:38.703168 32190 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:38.703214 32190 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:38.703269 32190 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:38.703645 32190 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/instance:
uuid: "ff8a157c724e45a6b7d74fbf02b208ce"
format_stamp: "Formatted at 2026-08-12 06:19:38 on dist-test-slave-gsp7"
I20260812 06:19:38.705127 32190 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:38.706087 32655 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:38.706322 32190 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:19:38.706387 32190 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root
uuid: "ff8a157c724e45a6b7d74fbf02b208ce"
format_stamp: "Formatted at 2026-08-12 06:19:38 on dist-test-slave-gsp7"
I20260812 06:19:38.706450 32190 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:38.715957 32190 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:38.716333 32190 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:38.716609 32190 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:38.717314 32190 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:38.717377 32190 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:38.717432 32190 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:38.717468 32190 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:38.724321 32190 rpc_server.cc:307] RPC server started. Bound to: 127.31.111.129:43397
I20260812 06:19:38.724390 32766 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.111.129:43397 every 8 connection(s)
I20260812 06:19:38.734138 32767 heartbeater.cc:344] Connected to a master server at 127.31.111.190:39963
I20260812 06:19:38.734287 32767 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:38.734561 32767 heartbeater.cc:507] Master 127.31.111.190:39963 requested a full tablet report, sending...
I20260812 06:19:38.735301 32543 ts_manager.cc:194] Registered new tserver with Master: ff8a157c724e45a6b7d74fbf02b208ce (127.31.111.129:43397)
I20260812 06:19:38.736038 32543 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50954
I20260812 06:19:38.736233 32190 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011157514s
I20260812 06:19:38.743379 32543 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50956:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:38.752301 32704 tablet_service.cc:1511] Processing CreateTablet for tablet 83eb033cb9204cc087ad9cf511f467cd (DEFAULT_TABLE table=heavy-update-compaction-test [id=ee7838be176d479fbbbc9d3a5c34b4ac]), partition=
I20260812 06:19:38.752612 32704 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 83eb033cb9204cc087ad9cf511f467cd. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:38.754714   315 tablet_bootstrap.cc:492] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Bootstrap starting.
I20260812 06:19:38.755555   315 tablet_bootstrap.cc:654] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:38.756593   315 tablet_bootstrap.cc:492] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: No bootstrap required, opened a new log
I20260812 06:19:38.756668   315 ts_tablet_manager.cc:1403] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:38.757058   315 raft_consensus.cc:359] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff8a157c724e45a6b7d74fbf02b208ce" member_type: VOTER last_known_addr { host: "127.31.111.129" port: 43397 } }
I20260812 06:19:38.757148   315 raft_consensus.cc:385] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:38.757171   315 raft_consensus.cc:740] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ff8a157c724e45a6b7d74fbf02b208ce, State: Initialized, Role: FOLLOWER
I20260812 06:19:38.757376   315 consensus_queue.cc:260] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce [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: "ff8a157c724e45a6b7d74fbf02b208ce" member_type: VOTER last_known_addr { host: "127.31.111.129" port: 43397 } }
I20260812 06:19:38.757539   315 raft_consensus.cc:399] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:38.757596   315 raft_consensus.cc:493] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:38.757642   315 raft_consensus.cc:3060] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:38.758495   315 raft_consensus.cc:515] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff8a157c724e45a6b7d74fbf02b208ce" member_type: VOTER last_known_addr { host: "127.31.111.129" port: 43397 } }
I20260812 06:19:38.758615   315 leader_election.cc:304] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce [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: ff8a157c724e45a6b7d74fbf02b208ce; no voters: 
I20260812 06:19:38.758775   315 leader_election.cc:290] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:38.758925   319 raft_consensus.cc:2804] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:38.759099 32767 heartbeater.cc:499] Master 127.31.111.190:39963 was elected leader, sending a full tablet report...
I20260812 06:19:38.759150   319 raft_consensus.cc:697] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce [term 1 LEADER]: Becoming Leader. State: Replica: ff8a157c724e45a6b7d74fbf02b208ce, State: Running, Role: LEADER
I20260812 06:19:38.759310   319 consensus_queue.cc:237] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce [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: "ff8a157c724e45a6b7d74fbf02b208ce" member_type: VOTER last_known_addr { host: "127.31.111.129" port: 43397 } }
I20260812 06:19:38.759419   315 ts_tablet_manager.cc:1434] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:38.760883 32543 catalog_manager.cc:5719] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce reported cstate change: term changed from 0 to 1, leader changed from <none> to ff8a157c724e45a6b7d74fbf02b208ce (127.31.111.129). New cstate: current_term: 1 leader_uuid: "ff8a157c724e45a6b7d74fbf02b208ce" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff8a157c724e45a6b7d74fbf02b208ce" member_type: VOTER last_known_addr { host: "127.31.111.129" port: 43397 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:38.821513 32190 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.011s	sys 0.012s
I20260812 06:19:38.975968   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushMRSOp(83eb033cb9204cc087ad9cf511f467cd): perf score=19.054940
I20260812 06:19:39.120865 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushMRSOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.145s	user 0.113s	sys 0.028s Metrics: {"bytes_written":12717735,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1231,"drs_written":1,"lbm_read_time_us":122,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36074,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":896,"update_count":1550}
I20260812 06:19:39.121636   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling LogGCOp(83eb033cb9204cc087ad9cf511f467cd): free 20743880 bytes of WAL
I20260812 06:19:39.121877 32663 log_reader.cc:385] T 83eb033cb9204cc087ad9cf511f467cd: removed 2 log segments from log reader
I20260812 06:19:39.121923 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000001 (ops 1-6)
I20260812 06:19:39.121953 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000002 (ops 7-11)
I20260812 06:19:39.126754 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: LogGCOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:39.127213   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:39.138989 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4408,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.139708   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:39.285576 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.146s	user 0.116s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":846,"lbm_read_time_us":10310,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24290,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"thread_start_us":392,"threads_started":5,"update_count":2000}
I20260812 06:19:39.286316   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling UndoDeltaBlockGCOp(83eb033cb9204cc087ad9cf511f467cd): 16411396 bytes on disk
I20260812 06:19:39.286814 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: UndoDeltaBlockGCOp(83eb033cb9204cc087ad9cf511f467cd) 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:19:39.287420   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=10.126437
I20260812 06:19:39.329221 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.042s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14346,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:39.329759   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:39.343791 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4744,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.344250   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:39.503793 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.159s	user 0.103s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":11353,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23919,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.504426   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=11.118625
I20260812 06:19:39.545035 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.040s	user 0.012s	sys 0.025s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17370,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:39.545744   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:39.570286 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.024s	user 0.006s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4957,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.570823   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:39.581300 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.581830   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:39.772190 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.190s	user 0.123s	sys 0.049s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":591,"lbm_read_time_us":11835,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29641,"lbm_writes_lt_1ms":543,"mutex_wait_us":268,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:19:39.772842   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=14.095187
I20260812 06:19:39.825114 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.052s	user 0.032s	sys 0.007s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18840,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:39.825675   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:39.838153 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4299,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.838699   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:39.983604 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.145s	user 0.110s	sys 0.031s 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":478,"lbm_read_time_us":9617,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28511,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:19:39.984350   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=11.118625
I20260812 06:19:40.020593 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.036s	user 0.016s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14433,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:40.021211   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:40.042814 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.021s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5480,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:40.043325   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:40.054508 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4081,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.055066   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:40.214574 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.159s	user 0.112s	sys 0.035s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":247,"lbm_read_time_us":11192,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28902,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24576,"update_count":2500}
I20260812 06:19:40.215193   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=14.095187
I20260812 06:19:40.282678 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.067s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":42303,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.283193   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:40.302642 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.019s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5726,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.303128   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushMRSOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:40.341245 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushMRSOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.038s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1261,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1527,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:40.342208   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling UndoDeltaBlockGCOp(83eb033cb9204cc087ad9cf511f467cd): 462 bytes on disk
I20260812 06:19:40.342726 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: UndoDeltaBlockGCOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:19:40.343359   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=3.181125
I20260812 06:19:40.354645 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4103,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:40.355154   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling LogGCOp(83eb033cb9204cc087ad9cf511f467cd): free 115943176 bytes of WAL
I20260812 06:19:40.355461 32663 log_reader.cc:385] T 83eb033cb9204cc087ad9cf511f467cd: removed 11 log segments from log reader
I20260812 06:19:40.355521 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000003 (ops 12-16)
I20260812 06:19:40.355561 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000004 (ops 17-21)
I20260812 06:19:40.355594 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000005 (ops 22-26)
I20260812 06:19:40.355616 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000006 (ops 27-31)
I20260812 06:19:40.355645 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000007 (ops 32-36)
I20260812 06:19:40.355680 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000008 (ops 37-41)
I20260812 06:19:40.355715 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000009 (ops 42-46)
I20260812 06:19:40.355743 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000010 (ops 47-51)
I20260812 06:19:40.355772 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000011 (ops 52-56)
I20260812 06:19:40.355801 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000012 (ops 57-61)
I20260812 06:19:40.355832 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000013 (ops 62-66)
I20260812 06:19:40.381559 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: LogGCOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:40.381994   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:40.414947 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.033s	user 0.006s	sys 0.017s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5515,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:40.415557   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:40.426371 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4219,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.426831   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:40.678079 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.251s	user 0.181s	sys 0.061s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082267,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":674,"lbm_read_time_us":17373,"lbm_reads_lt_1ms":875,"lbm_write_time_us":39477,"lbm_writes_lt_1ms":843,"mutex_wait_us":118,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":5760,"thread_start_us":112,"threads_started":1,"update_count":4000}
I20260812 06:19:40.678929   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=18.063937
I20260812 06:19:40.745851 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.066s	user 0.036s	sys 0.023s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26794,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:40.746479   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:40.760848 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.014s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5354,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.761514   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:40.967744 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.206s	user 0.129s	sys 0.065s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":402,"lbm_read_time_us":12566,"lbm_reads_lt_1ms":664,"lbm_write_time_us":32304,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3000}
I20260812 06:19:40.968532   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=18.063937
I20260812 06:19:41.038082 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.069s	user 0.039s	sys 0.024s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":27958,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:41.038581   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:41.050343 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.012s	user 0.001s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4186,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.050851   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:41.262367 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.211s	user 0.140s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":450,"lbm_read_time_us":14226,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32813,"lbm_writes_lt_1ms":643,"mutex_wait_us":65,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":28672,"update_count":3000}
I20260812 06:19:41.262909   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=18.063937
I20260812 06:19:41.337527 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.074s	user 0.040s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":28808,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:41.338105   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:41.350306 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.012s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4276,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.350813   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:41.556305 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.205s	user 0.129s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":232,"lbm_read_time_us":14259,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35024,"lbm_writes_lt_1ms":643,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":34048,"update_count":3000}
I20260812 06:19:41.557046   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=14.095187
I20260812 06:19:41.606935 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.050s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22198,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.607594   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:41.624020 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6820,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.624503   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:41.793859 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.169s	user 0.101s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":224,"lbm_read_time_us":11614,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28373,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:19:41.794595   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=14.095187
I20260812 06:19:41.852205 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.057s	user 0.020s	sys 0.033s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20735,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.852819   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:41.863881 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4204,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.864360   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushMRSOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:41.905655 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushMRSOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.041s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":264,"dirs.run_wall_time_us":1287,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1424,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:41.906324   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling LogGCOp(83eb033cb9204cc087ad9cf511f467cd): free 121006432 bytes of WAL
I20260812 06:19:41.906555 32663 log_reader.cc:385] T 83eb033cb9204cc087ad9cf511f467cd: removed 12 log segments from log reader
I20260812 06:19:41.906620 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000014 (ops 67-71)
I20260812 06:19:41.906673 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000015 (ops 72-76)
I20260812 06:19:41.906733 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000016 (ops 77-81)
I20260812 06:19:41.906773 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000017 (ops 82-86)
I20260812 06:19:41.906809 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000018 (ops 87-90)
I20260812 06:19:41.906874 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000019 (ops 91-95)
I20260812 06:19:41.906915 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000020 (ops 96-100)
I20260812 06:19:41.906953 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000021 (ops 101-105)
I20260812 06:19:41.906991 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000022 (ops 106-110)
I20260812 06:19:41.907027 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000023 (ops 111-115)
I20260812 06:19:41.907064 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000024 (ops 116-120)
I20260812 06:19:41.907100 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000025 (ops 121-125)
I20260812 06:19:41.932968 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: LogGCOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:41.933596   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling UndoDeltaBlockGCOp(83eb033cb9204cc087ad9cf511f467cd): 473 bytes on disk
I20260812 06:19:41.934113 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: UndoDeltaBlockGCOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:19:41.934666   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=3.181125
I20260812 06:19:41.956830 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.022s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6831,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:41.957372   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:41.967170 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.010s	user 0.003s	sys 0.005s 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:19:41.967667   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:42.187480 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.220s	user 0.146s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1686,"lbm_read_time_us":17362,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37409,"lbm_writes_lt_1ms":743,"mutex_wait_us":1182,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9472,"thread_start_us":100,"threads_started":1,"update_count":3500}
I20260812 06:19:42.188473   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=18.063937
I20260812 06:19:42.251286 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.063s	user 0.033s	sys 0.028s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27827,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:42.252149   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:42.268201 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5541,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.268738   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:42.428990 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.160s	user 0.135s	sys 0.024s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":224,"lbm_read_time_us":10973,"lbm_reads_lt_1ms":664,"lbm_write_time_us":32439,"lbm_writes_lt_1ms":643,"mutex_wait_us":53,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":3000}
I20260812 06:19:42.429729   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=14.095187
I20260812 06:19:42.471232 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.041s	user 0.027s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18790,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.472433   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:42.489702 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.017s	user 0.004s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6118,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.490199   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:42.657286 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.167s	user 0.122s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":814,"lbm_read_time_us":12051,"lbm_reads_lt_1ms":568,"lbm_write_time_us":32021,"lbm_writes_lt_1ms":543,"mutex_wait_us":406,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21504,"update_count":2500}
I20260812 06:19:42.658069   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=12.110812
I20260812 06:19:42.704424 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.046s	user 0.028s	sys 0.012s Metrics: {"bytes_written":13661282,"delete_count":0,"lbm_write_time_us":20599,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":335,"reinsert_count":0,"update_count":1665}
I20260812 06:19:42.705005   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.196750
I20260812 06:19:42.730805 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.026s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3159084,"delete_count":0,"lbm_write_time_us":4056,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:19:42.731494   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:42.741659 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3685,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:42.742357   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:42.935138 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.193s	user 0.128s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774771,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1426,"lbm_read_time_us":13189,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33132,"lbm_writes_lt_1ms":543,"mutex_wait_us":474,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:19:42.935786   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=14.095187
I20260812 06:19:42.995810 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.060s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21290,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.996325   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:43.007162 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4144,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.007807   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:43.191907 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.184s	user 0.130s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":203,"lbm_read_time_us":12762,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30291,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2500}
I20260812 06:19:43.192687   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=14.095187
I20260812 06:19:43.256906 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.064s	user 0.035s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20813,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.257691   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:43.269425 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4649,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.270002   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushMRSOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:43.309526 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushMRSOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.039s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1170,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1780,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:43.310322   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling LogGCOp(83eb033cb9204cc087ad9cf511f467cd): free 120553579 bytes of WAL
I20260812 06:19:43.310609 32663 log_reader.cc:385] T 83eb033cb9204cc087ad9cf511f467cd: removed 12 log segments from log reader
I20260812 06:19:43.310711 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000026 (ops 126-130)
I20260812 06:19:43.310804 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000027 (ops 131-134)
I20260812 06:19:43.310853 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000028 (ops 135-139)
I20260812 06:19:43.310914 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000029 (ops 140-144)
I20260812 06:19:43.310979 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000030 (ops 145-149)
I20260812 06:19:43.311034 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000031 (ops 150-154)
I20260812 06:19:43.311123 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000032 (ops 155-158)
I20260812 06:19:43.311187 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000033 (ops 159-163)
I20260812 06:19:43.311220 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000034 (ops 164-168)
I20260812 06:19:43.311252 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000035 (ops 169-173)
I20260812 06:19:43.311311 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000036 (ops 174-178)
I20260812 06:19:43.311355 32663 log.cc:1079] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: Deleting log segment in path: /tmp/dist-test-taskyz8Lhz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515572900942-32190-0/minicluster-data/ts-0-root/wals/83eb033cb9204cc087ad9cf511f467cd/wal-000000037 (ops 179-183)
I20260812 06:19:43.339326 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: LogGCOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:43.339772   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:43.354375 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.014s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4034,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.354825   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=2.188937
I20260812 06:19:43.365173 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.365756   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:43.585739 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.220s	user 0.148s	sys 0.070s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979748,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":421,"lbm_read_time_us":16050,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36655,"lbm_writes_lt_1ms":743,"mutex_wait_us":1252,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:19:43.586544   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=15.087375
I20260812 06:19:43.643080 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.056s	user 0.029s	sys 0.023s Metrics: {"bytes_written":16820146,"delete_count":0,"lbm_write_time_us":25926,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":409,"reinsert_count":0,"update_count":2050}
I20260812 06:19:43.643646   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling UndoDeltaBlockGCOp(83eb033cb9204cc087ad9cf511f467cd): 447 bytes on disk
I20260812 06:19:43.644083 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: UndoDeltaBlockGCOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:43.644630   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd): perf score=6.157687
I20260812 06:19:43.665563 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: FlushDeltaMemStoresOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.021s	user 0.020s	sys 0.000s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8465,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:43.666051   300 maintenance_manager.cc:419] P ff8a157c724e45a6b7d74fbf02b208ce: Scheduling MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd): perf score=1.000000
I20260812 06:19:43.692499 32190 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.871s	user 1.796s	sys 0.168s
I20260812 06:19:43.757911 32190 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.065s	user 0.003s	sys 0.000s
I20260812 06:19:43.758481 32190 tablet_server.cc:179] TabletServer@127.31.111.129:0 shutting down...
I20260812 06:19:43.835965 32663 maintenance_manager.cc:643] P ff8a157c724e45a6b7d74fbf02b208ce: MajorDeltaCompactionOp(83eb033cb9204cc087ad9cf511f467cd) complete. Timing: real 0.170s	user 0.120s	sys 0.047s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":555,"lbm_read_time_us":15917,"lbm_reads_lt_1ms":668,"lbm_write_time_us":31430,"lbm_writes_lt_1ms":643,"mutex_wait_us":1,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":25344,"update_count":3000}
I20260812 06:19:43.836748 32190 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:43.837021 32190 tablet_replica.cc:333] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce: stopping tablet replica
I20260812 06:19:43.837211 32190 raft_consensus.cc:2243] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:43.837451 32190 raft_consensus.cc:2272] T 83eb033cb9204cc087ad9cf511f467cd P ff8a157c724e45a6b7d74fbf02b208ce [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:43.853636 32190 tablet_server.cc:196] TabletServer@127.31.111.129:0 shutdown complete.
I20260812 06:19:43.890887 32190 master.cc:562] Master@127.31.111.190:39963 shutting down...
I20260812 06:19:43.894508 32190 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:43.894701 32190 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:43.894752 32190 tablet_replica.cc:333] T 00000000000000000000000000000000 P 77919babe78949838434742a7fa8fc59: stopping tablet replica
I20260812 06:19:43.907399 32190 master.cc:584] Master@127.31.111.190:39963 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5432 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11086 ms total)

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