[==========] 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:36.850828 21559 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.13.254:45475
I20260812 06:19:36.851884 21559 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:36.852510 21559 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:36.859143 21567 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:36.859181 21565 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:36.859457 21559 server_base.cc:1061] running on GCE node
W20260812 06:19:36.859472 21564 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:36.860065 21559 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:36.860198 21559 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:36.860266 21559 hybrid_clock.cc:648] HybridClock initialized: now 1786515576860262 us; error 0 us; skew 500 ppm
I20260812 06:19:36.862282 21559 webserver.cc:533] Webserver started at http://127.21.13.254:46455/ using document root <none> and password file <none>
I20260812 06:19:36.862944 21559 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:36.863040 21559 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:36.863329 21559 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:36.865134 21559 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/master-0-root/instance:
uuid: "0f96439bbdfc446097a9a32e6493f713"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-bt4h"
I20260812 06:19:36.868971 21559 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:36.871407 21573 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:36.872545 21559 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:36.872699 21559 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/master-0-root
uuid: "0f96439bbdfc446097a9a32e6493f713"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-bt4h"
I20260812 06:19:36.872835 21559 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-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:36.894707 21559 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:36.895440 21559 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:36.895651 21559 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:36.904237 21559 rpc_server.cc:307] RPC server started. Bound to: 127.21.13.254:45475
I20260812 06:19:36.904253 21633 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.13.254:45475 every 8 connection(s)
I20260812 06:19:36.906811 21634 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:36.913014 21634 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713: Bootstrap starting.
I20260812 06:19:36.915758 21634 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:36.916849 21634 log.cc:826] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:36.919008 21634 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713: No bootstrap required, opened a new log
I20260812 06:19:36.922269 21634 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0f96439bbdfc446097a9a32e6493f713" member_type: VOTER }
I20260812 06:19:36.922477 21634 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:36.922591 21634 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0f96439bbdfc446097a9a32e6493f713, State: Initialized, Role: FOLLOWER
I20260812 06:19:36.923332 21634 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [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: "0f96439bbdfc446097a9a32e6493f713" member_type: VOTER }
I20260812 06:19:36.923532 21634 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:36.923623 21634 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:36.923823 21634 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:36.924820 21634 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0f96439bbdfc446097a9a32e6493f713" member_type: VOTER }
I20260812 06:19:36.925355 21634 leader_election.cc:304] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [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: 0f96439bbdfc446097a9a32e6493f713; no voters: 
I20260812 06:19:36.925757 21634 leader_election.cc:290] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:36.926018 21637 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:36.926286 21637 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [term 1 LEADER]: Becoming Leader. State: Replica: 0f96439bbdfc446097a9a32e6493f713, State: Running, Role: LEADER
I20260812 06:19:36.926744 21637 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [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: "0f96439bbdfc446097a9a32e6493f713" member_type: VOTER }
I20260812 06:19:36.927078 21634 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:36.928871 21639 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0f96439bbdfc446097a9a32e6493f713. Latest consensus state: current_term: 1 leader_uuid: "0f96439bbdfc446097a9a32e6493f713" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0f96439bbdfc446097a9a32e6493f713" member_type: VOTER } }
I20260812 06:19:36.928828 21638 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0f96439bbdfc446097a9a32e6493f713" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0f96439bbdfc446097a9a32e6493f713" member_type: VOTER } }
I20260812 06:19:36.929020 21639 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:36.929020 21638 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:36.929451 21651 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:36.929698 21559 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:36.932127 21651 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:36.936975 21651 catalog_manager.cc:1383] Generated new cluster ID: 90cc89415fe94fe4b77ba0c9263f66fc
I20260812 06:19:36.937062 21651 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:36.945204 21651 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:36.946408 21651 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:36.956348 21651 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713: Generated new TSK 0
I20260812 06:19:36.957165 21651 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:36.962239 21559 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:36.965204 21660 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:36.965284 21659 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:36.965517 21662 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:36.965574 21559 server_base.cc:1061] running on GCE node
I20260812 06:19:36.965844 21559 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:36.965894 21559 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:36.965917 21559 hybrid_clock.cc:648] HybridClock initialized: now 1786515576965917 us; error 0 us; skew 500 ppm
I20260812 06:19:36.966909 21559 webserver.cc:533] Webserver started at http://127.21.13.193:36471/ using document root <none> and password file <none>
I20260812 06:19:36.967085 21559 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:36.967149 21559 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:36.967232 21559 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:36.967710 21559 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/instance:
uuid: "dea2296bcbda4b3bb34fcb6cfca84058"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-bt4h"
I20260812 06:19:36.969625 21559 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:36.970852 21668 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:36.971107 21559 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:36.971184 21559 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root
uuid: "dea2296bcbda4b3bb34fcb6cfca84058"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-bt4h"
I20260812 06:19:36.971247 21559 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-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:36.979799 21559 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:36.980321 21559 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:36.980870 21559 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:36.981774 21559 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:36.981827 21559 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:36.981901 21559 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:36.981945 21559 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:36.989481 21559 rpc_server.cc:307] RPC server started. Bound to: 127.21.13.193:40963
I20260812 06:19:36.989503 21737 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.13.193:40963 every 8 connection(s)
I20260812 06:19:37.000435 21738 heartbeater.cc:344] Connected to a master server at 127.21.13.254:45475
I20260812 06:19:37.000751 21738 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:37.001324 21738 heartbeater.cc:507] Master 127.21.13.254:45475 requested a full tablet report, sending...
I20260812 06:19:37.002948 21591 ts_manager.cc:194] Registered new tserver with Master: dea2296bcbda4b3bb34fcb6cfca84058 (127.21.13.193:40963)
I20260812 06:19:37.003758 21559 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013544555s
I20260812 06:19:37.004346 21591 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51790
I20260812 06:19:37.013904 21591 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51806:
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:37.029496 21699 tablet_service.cc:1511] Processing CreateTablet for tablet 065b5747470749468ce749892b33e6e6 (DEFAULT_TABLE table=heavy-update-compaction-test [id=25c8634ae15744e2ab13f39669d7eeca]), partition=
I20260812 06:19:37.030052 21699 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 065b5747470749468ce749892b33e6e6. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:37.033018 21752 tablet_bootstrap.cc:492] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Bootstrap starting.
I20260812 06:19:37.034152 21752 tablet_bootstrap.cc:654] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:37.035674 21752 tablet_bootstrap.cc:492] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: No bootstrap required, opened a new log
I20260812 06:19:37.035799 21752 ts_tablet_manager.cc:1403] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:37.036536 21752 raft_consensus.cc:359] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dea2296bcbda4b3bb34fcb6cfca84058" member_type: VOTER last_known_addr { host: "127.21.13.193" port: 40963 } }
I20260812 06:19:37.036688 21752 raft_consensus.cc:385] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:37.036752 21752 raft_consensus.cc:740] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: dea2296bcbda4b3bb34fcb6cfca84058, State: Initialized, Role: FOLLOWER
I20260812 06:19:37.036904 21752 consensus_queue.cc:260] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058 [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: "dea2296bcbda4b3bb34fcb6cfca84058" member_type: VOTER last_known_addr { host: "127.21.13.193" port: 40963 } }
I20260812 06:19:37.037019 21752 raft_consensus.cc:399] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:37.037088 21752 raft_consensus.cc:493] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:37.037155 21752 raft_consensus.cc:3060] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:37.038077 21752 raft_consensus.cc:515] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dea2296bcbda4b3bb34fcb6cfca84058" member_type: VOTER last_known_addr { host: "127.21.13.193" port: 40963 } }
I20260812 06:19:37.038273 21752 leader_election.cc:304] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058 [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: dea2296bcbda4b3bb34fcb6cfca84058; no voters: 
I20260812 06:19:37.038609 21752 leader_election.cc:290] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:37.038738 21754 raft_consensus.cc:2804] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:37.039026 21754 raft_consensus.cc:697] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058 [term 1 LEADER]: Becoming Leader. State: Replica: dea2296bcbda4b3bb34fcb6cfca84058, State: Running, Role: LEADER
I20260812 06:19:37.039036 21752 ts_tablet_manager.cc:1434] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:37.039279 21738 heartbeater.cc:499] Master 127.21.13.254:45475 was elected leader, sending a full tablet report...
I20260812 06:19:37.039273 21754 consensus_queue.cc:237] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058 [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: "dea2296bcbda4b3bb34fcb6cfca84058" member_type: VOTER last_known_addr { host: "127.21.13.193" port: 40963 } }
I20260812 06:19:37.042375 21590 catalog_manager.cc:5719] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058 reported cstate change: term changed from 0 to 1, leader changed from <none> to dea2296bcbda4b3bb34fcb6cfca84058 (127.21.13.193). New cstate: current_term: 1 leader_uuid: "dea2296bcbda4b3bb34fcb6cfca84058" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dea2296bcbda4b3bb34fcb6cfca84058" member_type: VOTER last_known_addr { host: "127.21.13.193" port: 40963 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:37.125450 21559 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.075s	user 0.021s	sys 0.010s
I20260812 06:19:37.240813 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushMRSOp(065b5747470749468ce749892b33e6e6): perf score=15.086190
I20260812 06:19:37.412133 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushMRSOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.171s	user 0.116s	sys 0.051s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":253,"delete_count":0,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":722,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43649,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":155,"threads_started":1,"update_count":1500}
I20260812 06:19:37.413650 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling LogGCOp(065b5747470749468ce749892b33e6e6): free 11976772 bytes of WAL
I20260812 06:19:37.414121 21673 log_reader.cc:385] T 065b5747470749468ce749892b33e6e6: removed 1 log segments from log reader
I20260812 06:19:37.414215 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000001 (ops 1-6)
I20260812 06:19:37.418210 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: LogGCOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:37.418709 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:37.436297 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.017s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":6424,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.437031 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:37.584720 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.147s	user 0.104s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":952,"lbm_read_time_us":11323,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27231,"lbm_writes_lt_1ms":443,"mutex_wait_us":203,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":357,"threads_started":5,"update_count":2000}
I20260812 06:19:37.585525 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling UndoDeltaBlockGCOp(065b5747470749468ce749892b33e6e6): 12308959 bytes on disk
I20260812 06:19:37.586221 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: UndoDeltaBlockGCOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:19:37.586822 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=11.118625
I20260812 06:19:37.622984 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.036s	user 0.022s	sys 0.013s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15867,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:37.623534 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:37.648509 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.025s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5238,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:37.648952 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:37.660125 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4445,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.660699 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:37.816068 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.155s	user 0.119s	sys 0.032s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733833,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":204,"lbm_read_time_us":11447,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31760,"lbm_writes_lt_1ms":543,"mutex_wait_us":178,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2500}
I20260812 06:19:37.816670 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=11.118625
I20260812 06:19:37.858525 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.042s	user 0.025s	sys 0.013s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18266,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:37.859268 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:37.886961 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.028s	user 0.009s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6032,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:37.887478 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:37.898665 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4417,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.899329 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:38.086881 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.187s	user 0.132s	sys 0.035s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733835,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":259,"lbm_read_time_us":12370,"lbm_reads_lt_1ms":573,"lbm_write_time_us":35171,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:19:38.087607 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=14.095187
I20260812 06:19:38.149506 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.062s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22973,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.149966 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:38.161190 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4391,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.162019 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:38.364125 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.202s	user 0.131s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":190,"lbm_read_time_us":13025,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34854,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:38.364794 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=14.095187
I20260812 06:19:38.435511 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.071s	user 0.031s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":30129,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.436102 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:38.448944 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4935,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.449502 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:38.626282 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.177s	user 0.108s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":214,"lbm_read_time_us":12818,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30660,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:19:38.626945 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=14.095187
I20260812 06:19:38.690887 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.064s	user 0.025s	sys 0.030s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19300,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.691573 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:38.702790 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4403,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.703299 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushMRSOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:38.747154 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushMRSOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.044s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":1492,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1649,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:38.748090 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling LogGCOp(065b5747470749468ce749892b33e6e6): free 116849502 bytes of WAL
I20260812 06:19:38.748384 21673 log_reader.cc:385] T 065b5747470749468ce749892b33e6e6: removed 12 log segments from log reader
I20260812 06:19:38.748464 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000002 (ops 7-11)
I20260812 06:19:38.748531 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000003 (ops 12-16)
I20260812 06:19:38.748577 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000004 (ops 17-20)
I20260812 06:19:38.748620 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000005 (ops 21-25)
I20260812 06:19:38.748661 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000006 (ops 26-30)
I20260812 06:19:38.748696 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000007 (ops 31-34)
I20260812 06:19:38.748735 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000008 (ops 35-39)
I20260812 06:19:38.748785 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000009 (ops 40-44)
I20260812 06:19:38.748824 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000010 (ops 45-49)
I20260812 06:19:38.748865 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000011 (ops 50-54)
I20260812 06:19:38.748906 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000012 (ops 55-58)
I20260812 06:19:38.748947 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000013 (ops 59-63)
I20260812 06:19:38.781934 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: LogGCOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.034s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:19:38.782660 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:38.803158 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.020s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4612,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.803750 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:38.815138 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4417,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.815815 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling UndoDeltaBlockGCOp(065b5747470749468ce749892b33e6e6): 463 bytes on disk
I20260812 06:19:38.816478 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: UndoDeltaBlockGCOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:38.817108 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:39.050716 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.233s	user 0.150s	sys 0.083s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938785,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1558,"lbm_read_time_us":18395,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43070,"lbm_writes_lt_1ms":743,"mutex_wait_us":499,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":20608,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:19:39.051446 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=14.095187
I20260812 06:19:39.113883 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.062s	user 0.038s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":28489,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.114391 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:39.138743 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.024s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5376,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.139215 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:39.150332 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4242,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.150966 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:39.328389 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.177s	user 0.138s	sys 0.039s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836256,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":621,"lbm_read_time_us":14370,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36742,"lbm_writes_lt_1ms":643,"mutex_wait_us":331,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":3000}
I20260812 06:19:39.329237 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=14.095187
I20260812 06:19:39.388266 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.059s	user 0.028s	sys 0.028s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":28719,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.388814 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:39.402004 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5232,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.402570 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:39.578715 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.176s	user 0.115s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":288,"lbm_read_time_us":12770,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30785,"lbm_writes_lt_1ms":543,"mutex_wait_us":88,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:19:39.579485 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=14.095187
I20260812 06:19:39.625456 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.046s	user 0.029s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21191,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.626032 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:39.777753 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.152s	user 0.111s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631193,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":247,"lbm_read_time_us":10528,"lbm_reads_lt_1ms":467,"lbm_write_time_us":28910,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2000}
I20260812 06:19:39.778455 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=10.126437
I20260812 06:19:39.813143 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.034s	user 0.027s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14607,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:39.813721 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:39.829947 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6427,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.830408 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:39.965128 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.135s	user 0.083s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":66,"lbm_read_time_us":8826,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27174,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2000}
I20260812 06:19:39.966118 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=10.126437
I20260812 06:19:40.003096 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.036s	user 0.021s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15089,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:40.003602 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:40.019789 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.020463 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:40.145565 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.125s	user 0.097s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":273,"lbm_read_time_us":9339,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27595,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20864,"update_count":2000}
I20260812 06:19:40.146395 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=10.126437
I20260812 06:19:40.185756 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.039s	user 0.019s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15770,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:40.186347 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:40.202409 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6088,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.203085 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushMRSOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:40.235399 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushMRSOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.032s	user 0.023s	sys 0.005s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":273,"dirs.run_wall_time_us":1518,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1589,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:40.236186 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling LogGCOp(065b5747470749468ce749892b33e6e6): free 124710300 bytes of WAL
I20260812 06:19:40.236451 21673 log_reader.cc:385] T 065b5747470749468ce749892b33e6e6: removed 12 log segments from log reader
I20260812 06:19:40.236519 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000014 (ops 64-68)
I20260812 06:19:40.236583 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000015 (ops 69-73)
I20260812 06:19:40.236647 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000016 (ops 74-78)
I20260812 06:19:40.236696 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000017 (ops 79-83)
I20260812 06:19:40.236745 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000018 (ops 84-88)
I20260812 06:19:40.236789 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000019 (ops 89-93)
I20260812 06:19:40.236832 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000020 (ops 94-98)
I20260812 06:19:40.236876 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000021 (ops 99-103)
I20260812 06:19:40.236918 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000022 (ops 104-108)
I20260812 06:19:40.236960 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000023 (ops 109-113)
I20260812 06:19:40.237002 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000024 (ops 114-118)
I20260812 06:19:40.237044 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000025 (ops 119-123)
I20260812 06:19:40.266449 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: LogGCOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:40.266925 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling UndoDeltaBlockGCOp(065b5747470749468ce749892b33e6e6): 462 bytes on disk
I20260812 06:19:40.267582 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: UndoDeltaBlockGCOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:19:40.268159 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=3.181125
I20260812 06:19:40.286862 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.018s	user 0.006s	sys 0.012s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7418,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:40.287348 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:40.297819 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3862,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:40.298307 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:40.476735 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.178s	user 0.136s	sys 0.035s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836361,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1212,"lbm_read_time_us":14243,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34479,"lbm_writes_lt_1ms":643,"mutex_wait_us":67,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3072,"thread_start_us":94,"threads_started":1,"update_count":3000}
I20260812 06:19:40.477567 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=14.095187
I20260812 06:19:40.525753 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.048s	user 0.035s	sys 0.009s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20752,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.526355 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:40.542403 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5992,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.543004 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:40.719046 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.176s	user 0.112s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":276,"lbm_read_time_us":10541,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32124,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:40.719780 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=14.095187
I20260812 06:19:40.776275 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.056s	user 0.032s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22358,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.776819 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:40.789041 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4475,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.789561 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:40.974987 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.185s	user 0.119s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":454,"lbm_read_time_us":13007,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31700,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":2500}
I20260812 06:19:40.975715 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=14.095187
I20260812 06:19:41.041625 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.066s	user 0.028s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25599,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.042162 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:41.054924 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4520,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.055425 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:41.241993 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.186s	user 0.120s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":836,"lbm_read_time_us":15135,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30299,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:19:41.242738 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=14.095187
I20260812 06:19:41.305495 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.063s	user 0.016s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18626,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.306079 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:41.317178 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.317734 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:41.508000 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.190s	user 0.118s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":162,"lbm_read_time_us":13562,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32165,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":45184,"update_count":2500}
I20260812 06:19:41.508646 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=11.118625
I20260812 06:19:41.549021 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.040s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16949,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:41.549729 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:41.569013 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.019s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5282,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:41.569785 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:41.731848 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.162s	user 0.096s	sys 0.055s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1182,"lbm_read_time_us":10317,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25066,"lbm_writes_lt_1ms":443,"mutex_wait_us":321,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.732589 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=14.095187
I20260812 06:19:41.786077 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.053s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22441,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.786739 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:41.802589 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5768,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.803373 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushMRSOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:41.837822 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushMRSOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.034s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":97,"dirs.run_cpu_time_us":268,"dirs.run_wall_time_us":1499,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1872,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:41.838587 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling LogGCOp(065b5747470749468ce749892b33e6e6): free 133024624 bytes of WAL
I20260812 06:19:41.838842 21673 log_reader.cc:385] T 065b5747470749468ce749892b33e6e6: removed 13 log segments from log reader
I20260812 06:19:41.838886 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000026 (ops 124-128)
I20260812 06:19:41.838914 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000027 (ops 129-133)
I20260812 06:19:41.838972 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000028 (ops 134-138)
I20260812 06:19:41.839028 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000029 (ops 139-143)
I20260812 06:19:41.839057 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000030 (ops 144-148)
I20260812 06:19:41.839113 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000031 (ops 149-153)
I20260812 06:19:41.839154 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000032 (ops 154-158)
I20260812 06:19:41.839198 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000033 (ops 159-163)
I20260812 06:19:41.839238 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000034 (ops 164-168)
I20260812 06:19:41.839277 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000035 (ops 169-173)
I20260812 06:19:41.839315 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000036 (ops 174-178)
I20260812 06:19:41.839354 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000037 (ops 179-182)
I20260812 06:19:41.839394 21673 log.cc:1079] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/065b5747470749468ce749892b33e6e6/wal-000000038 (ops 183-187)
I20260812 06:19:41.868230 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: LogGCOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:41.868721 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=4.173312
I20260812 06:19:41.898429 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.030s	user 0.014s	sys 0.011s Metrics: {"bytes_written":5333393,"delete_count":0,"lbm_write_time_us":6628,"lbm_writes_lt_1ms":133,"reinsert_count":0,"update_count":650}
I20260812 06:19:41.899067 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=1.196750
I20260812 06:19:41.908172 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":3324,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:19:41.908672 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling UndoDeltaBlockGCOp(065b5747470749468ce749892b33e6e6): 483 bytes on disk
I20260812 06:19:41.909098 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: UndoDeltaBlockGCOp(065b5747470749468ce749892b33e6e6) 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:41.909590 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:42.158401 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.249s	user 0.168s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938761,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":457,"lbm_read_time_us":17590,"lbm_reads_lt_1ms":774,"lbm_write_time_us":44100,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":15104,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:19:42.159219 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=14.095187
I20260812 06:19:42.224525 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.065s	user 0.041s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26251,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.225236 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6): perf score=2.188937
I20260812 06:19:42.237946 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: FlushDeltaMemStoresOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5071,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.238485 21739 maintenance_manager.cc:419] P dea2296bcbda4b3bb34fcb6cfca84058: Scheduling MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6): perf score=1.000000
I20260812 06:19:42.293241 21559 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.168s	user 1.853s	sys 0.180s
I20260812 06:19:42.368106 21559 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.074s	user 0.002s	sys 0.000s
I20260812 06:19:42.368781 21559 tablet_server.cc:179] TabletServer@127.21.13.193:0 shutting down...
I20260812 06:19:42.412022 21673 maintenance_manager.cc:643] P dea2296bcbda4b3bb34fcb6cfca84058: MajorDeltaCompactionOp(065b5747470749468ce749892b33e6e6) complete. Timing: real 0.173s	user 0.120s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":426,"lbm_read_time_us":13531,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28447,"lbm_writes_lt_1ms":543,"mutex_wait_us":83,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:42.412822 21559 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:42.413239 21559 tablet_replica.cc:333] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058: stopping tablet replica
I20260812 06:19:42.413465 21559 raft_consensus.cc:2243] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:42.413743 21559 raft_consensus.cc:2272] T 065b5747470749468ce749892b33e6e6 P dea2296bcbda4b3bb34fcb6cfca84058 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:42.430341 21559 tablet_server.cc:196] TabletServer@127.21.13.193:0 shutdown complete.
I20260812 06:19:42.459746 21559 master.cc:562] Master@127.21.13.254:45475 shutting down...
I20260812 06:19:42.464109 21559 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:42.464378 21559 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:42.464494 21559 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0f96439bbdfc446097a9a32e6493f713: stopping tablet replica
I20260812 06:19:42.477286 21559 master.cc:584] Master@127.21.13.254:45475 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5731 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:42.598734 21559 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.13.254:44109
I20260812 06:19:42.599215 21559 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:42.601985 21559 server_base.cc:1061] running on GCE node
W20260812 06:19:42.602023 21775 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:42.602090 21772 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:42.602113 21773 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:42.602443 21559 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:42.602486 21559 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:42.602501 21559 hybrid_clock.cc:648] HybridClock initialized: now 1786515582602501 us; error 0 us; skew 500 ppm
I20260812 06:19:42.603463 21559 webserver.cc:533] Webserver started at http://127.21.13.254:34713/ using document root <none> and password file <none>
I20260812 06:19:42.603606 21559 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:42.603652 21559 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:42.603705 21559 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:42.604070 21559 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/master-0-root/instance:
uuid: "f10a780380a94dffa7fc59d4bdf08f6f"
format_stamp: "Formatted at 2026-08-12 06:19:42 on dist-test-slave-bt4h"
I20260812 06:19:42.605587 21559 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:42.607365 21781 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:42.607659 21559 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:42.607769 21559 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/master-0-root
uuid: "f10a780380a94dffa7fc59d4bdf08f6f"
format_stamp: "Formatted at 2026-08-12 06:19:42 on dist-test-slave-bt4h"
I20260812 06:19:42.607856 21559 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-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:42.627103 21559 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:42.627563 21559 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:42.632084 21559 rpc_server.cc:307] RPC server started. Bound to: 127.21.13.254:44109
I20260812 06:19:42.635475 21839 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.13.254:44109 every 8 connection(s)
I20260812 06:19:42.636102 21840 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:42.638103 21840 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f: Bootstrap starting.
I20260812 06:19:42.638996 21840 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:42.640091 21840 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f: No bootstrap required, opened a new log
I20260812 06:19:42.640543 21840 raft_consensus.cc:359] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f10a780380a94dffa7fc59d4bdf08f6f" member_type: VOTER }
I20260812 06:19:42.640666 21840 raft_consensus.cc:385] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:42.640733 21840 raft_consensus.cc:740] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f10a780380a94dffa7fc59d4bdf08f6f, State: Initialized, Role: FOLLOWER
I20260812 06:19:42.640908 21840 consensus_queue.cc:260] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [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: "f10a780380a94dffa7fc59d4bdf08f6f" member_type: VOTER }
I20260812 06:19:42.641011 21840 raft_consensus.cc:399] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:42.641070 21840 raft_consensus.cc:493] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:42.641135 21840 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:42.641921 21840 raft_consensus.cc:515] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f10a780380a94dffa7fc59d4bdf08f6f" member_type: VOTER }
I20260812 06:19:42.642092 21840 leader_election.cc:304] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [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: f10a780380a94dffa7fc59d4bdf08f6f; no voters: 
I20260812 06:19:42.642313 21840 leader_election.cc:290] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:42.642426 21843 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:42.642707 21843 raft_consensus.cc:697] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [term 1 LEADER]: Becoming Leader. State: Replica: f10a780380a94dffa7fc59d4bdf08f6f, State: Running, Role: LEADER
I20260812 06:19:42.642915 21840 sys_catalog.cc:565] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:42.642890 21843 consensus_queue.cc:237] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [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: "f10a780380a94dffa7fc59d4bdf08f6f" member_type: VOTER }
I20260812 06:19:42.643342 21844 sys_catalog.cc:455] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f10a780380a94dffa7fc59d4bdf08f6f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f10a780380a94dffa7fc59d4bdf08f6f" member_type: VOTER } }
I20260812 06:19:42.643452 21844 sys_catalog.cc:458] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:42.643356 21845 sys_catalog.cc:455] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [sys.catalog]: SysCatalogTable state changed. Reason: New leader f10a780380a94dffa7fc59d4bdf08f6f. Latest consensus state: current_term: 1 leader_uuid: "f10a780380a94dffa7fc59d4bdf08f6f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f10a780380a94dffa7fc59d4bdf08f6f" member_type: VOTER } }
I20260812 06:19:42.643582 21845 sys_catalog.cc:458] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:42.644104 21847 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:42.644794 21847 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:42.645154 21559 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:42.646838 21847 catalog_manager.cc:1383] Generated new cluster ID: 1779509a6f82432993559d13b29a7034
I20260812 06:19:42.646886 21847 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:42.656198 21847 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:42.656780 21847 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:42.662175 21847 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f: Generated new TSK 0
I20260812 06:19:42.662406 21847 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:42.677610 21559 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:42.679798 21862 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:42.679841 21864 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:42.679888 21559 server_base.cc:1061] running on GCE node
W20260812 06:19:42.679852 21866 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:42.680187 21559 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:42.680230 21559 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:42.680246 21559 hybrid_clock.cc:648] HybridClock initialized: now 1786515582680247 us; error 0 us; skew 500 ppm
I20260812 06:19:42.681141 21559 webserver.cc:533] Webserver started at http://127.21.13.193:39833/ using document root <none> and password file <none>
I20260812 06:19:42.681282 21559 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:42.681329 21559 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:42.681399 21559 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:42.681756 21559 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/instance:
uuid: "7cf7a83e9d6c4c2099f546294c9e4477"
format_stamp: "Formatted at 2026-08-12 06:19:42 on dist-test-slave-bt4h"
I20260812 06:19:42.683329 21559 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:42.684432 21871 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:42.684731 21559 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:42.684870 21559 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root
uuid: "7cf7a83e9d6c4c2099f546294c9e4477"
format_stamp: "Formatted at 2026-08-12 06:19:42 on dist-test-slave-bt4h"
I20260812 06:19:42.684960 21559 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-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:42.703426 21559 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:42.703869 21559 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:42.704205 21559 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:42.704711 21559 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:42.704773 21559 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:42.704838 21559 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:42.704875 21559 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:42.709693 21559 rpc_server.cc:307] RPC server started. Bound to: 127.21.13.193:39137
I20260812 06:19:42.711131 21939 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.13.193:39137 every 8 connection(s)
I20260812 06:19:42.720672 21940 heartbeater.cc:344] Connected to a master server at 127.21.13.254:44109
I20260812 06:19:42.720824 21940 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:42.721113 21940 heartbeater.cc:507] Master 127.21.13.254:44109 requested a full tablet report, sending...
I20260812 06:19:42.721920 21800 ts_manager.cc:194] Registered new tserver with Master: 7cf7a83e9d6c4c2099f546294c9e4477 (127.21.13.193:39137)
I20260812 06:19:42.722679 21559 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01222029s
I20260812 06:19:42.722761 21800 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34802
I20260812 06:19:42.730319 21800 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34818:
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:42.739616 21902 tablet_service.cc:1511] Processing CreateTablet for tablet a830801c35db4fe9add4f1768021e9d9 (DEFAULT_TABLE table=heavy-update-compaction-test [id=c180c579630d4406bdd0435483b150c3]), partition=
I20260812 06:19:42.739938 21902 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a830801c35db4fe9add4f1768021e9d9. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:42.742110 21956 tablet_bootstrap.cc:492] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Bootstrap starting.
I20260812 06:19:42.743108 21956 tablet_bootstrap.cc:654] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:42.744390 21956 tablet_bootstrap.cc:492] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: No bootstrap required, opened a new log
I20260812 06:19:42.744495 21956 ts_tablet_manager.cc:1403] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:42.745107 21956 raft_consensus.cc:359] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7cf7a83e9d6c4c2099f546294c9e4477" member_type: VOTER last_known_addr { host: "127.21.13.193" port: 39137 } }
I20260812 06:19:42.745242 21956 raft_consensus.cc:385] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:42.745281 21956 raft_consensus.cc:740] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7cf7a83e9d6c4c2099f546294c9e4477, State: Initialized, Role: FOLLOWER
I20260812 06:19:42.745420 21956 consensus_queue.cc:260] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477 [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: "7cf7a83e9d6c4c2099f546294c9e4477" member_type: VOTER last_known_addr { host: "127.21.13.193" port: 39137 } }
I20260812 06:19:42.745574 21956 raft_consensus.cc:399] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:42.745656 21956 raft_consensus.cc:493] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:42.745720 21956 raft_consensus.cc:3060] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:42.746932 21956 raft_consensus.cc:515] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7cf7a83e9d6c4c2099f546294c9e4477" member_type: VOTER last_known_addr { host: "127.21.13.193" port: 39137 } }
I20260812 06:19:42.747089 21956 leader_election.cc:304] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477 [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: 7cf7a83e9d6c4c2099f546294c9e4477; no voters: 
I20260812 06:19:42.747324 21956 leader_election.cc:290] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:42.747529 21958 raft_consensus.cc:2804] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:42.747747 21958 raft_consensus.cc:697] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477 [term 1 LEADER]: Becoming Leader. State: Replica: 7cf7a83e9d6c4c2099f546294c9e4477, State: Running, Role: LEADER
I20260812 06:19:42.747834 21956 ts_tablet_manager.cc:1434] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.004s
I20260812 06:19:42.747834 21940 heartbeater.cc:499] Master 127.21.13.254:44109 was elected leader, sending a full tablet report...
I20260812 06:19:42.747916 21958 consensus_queue.cc:237] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477 [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: "7cf7a83e9d6c4c2099f546294c9e4477" member_type: VOTER last_known_addr { host: "127.21.13.193" port: 39137 } }
I20260812 06:19:42.749341 21800 catalog_manager.cc:5719] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477 reported cstate change: term changed from 0 to 1, leader changed from <none> to 7cf7a83e9d6c4c2099f546294c9e4477 (127.21.13.193). New cstate: current_term: 1 leader_uuid: "7cf7a83e9d6c4c2099f546294c9e4477" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7cf7a83e9d6c4c2099f546294c9e4477" member_type: VOTER last_known_addr { host: "127.21.13.193" port: 39137 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:42.811587 21559 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.010s	sys 0.013s
I20260812 06:19:42.961678 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushMRSOp(a830801c35db4fe9add4f1768021e9d9): perf score=19.054940
I20260812 06:19:43.132162 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushMRSOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.170s	user 0.114s	sys 0.055s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":949,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40773,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:19:43.132897 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling LogGCOp(a830801c35db4fe9add4f1768021e9d9): free 20290830 bytes of WAL
I20260812 06:19:43.133158 21876 log_reader.cc:385] T a830801c35db4fe9add4f1768021e9d9: removed 2 log segments from log reader
I20260812 06:19:43.133204 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000001 (ops 1-6)
I20260812 06:19:43.133236 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000002 (ops 7-10)
I20260812 06:19:43.137710 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: LogGCOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:43.138152 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:43.151474 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5129,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.152182 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:43.308902 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.157s	user 0.081s	sys 0.076s 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":515,"lbm_read_time_us":12648,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26313,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"thread_start_us":325,"threads_started":5,"update_count":2000}
I20260812 06:19:43.309618 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling UndoDeltaBlockGCOp(a830801c35db4fe9add4f1768021e9d9): 16411397 bytes on disk
I20260812 06:19:43.310141 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: UndoDeltaBlockGCOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4}
I20260812 06:19:43.310818 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=11.118625
I20260812 06:19:43.356525 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.046s	user 0.030s	sys 0.012s Metrics: {"bytes_written":12635685,"delete_count":0,"lbm_write_time_us":21716,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1540}
I20260812 06:19:43.357095 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:43.385550 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.028s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":5641,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:19:43.386030 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:43.397282 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4447,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.397922 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:43.571384 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.173s	user 0.133s	sys 0.035s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774802,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":149,"lbm_read_time_us":13122,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33686,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:19:43.572059 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=11.118625
I20260812 06:19:43.610036 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.038s	user 0.017s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16404,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:43.610598 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:43.633421 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.023s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4841,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:43.633888 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:43.645220 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4382,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.645933 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:43.799031 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.153s	user 0.108s	sys 0.040s 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":984,"lbm_read_time_us":11922,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31950,"lbm_writes_lt_1ms":543,"mutex_wait_us":334,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:19:43.799757 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=11.118625
I20260812 06:19:43.849116 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.049s	user 0.037s	sys 0.005s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":19307,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:43.849671 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:43.867206 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6721,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.867671 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:43.878069 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4074,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:43.878686 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:44.042253 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.163s	user 0.125s	sys 0.038s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":101,"lbm_read_time_us":12973,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32302,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":29312,"update_count":2500}
I20260812 06:19:44.042968 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=10.126437
I20260812 06:19:44.081472 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.038s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16050,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:44.082103 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:44.097927 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5636,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.098387 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:44.246208 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.148s	user 0.103s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":872,"lbm_read_time_us":10911,"lbm_reads_lt_1ms":468,"lbm_write_time_us":28471,"lbm_writes_lt_1ms":443,"mutex_wait_us":427,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2000}
I20260812 06:19:44.246809 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=10.126437
I20260812 06:19:44.302781 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.056s	user 0.031s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17159,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:44.303417 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:44.314904 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4462,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.315402 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:44.471307 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.156s	user 0.084s	sys 0.072s 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":403,"lbm_read_time_us":12015,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25290,"lbm_writes_lt_1ms":443,"mutex_wait_us":91,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:19:44.471987 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=10.126437
I20260812 06:19:44.518414 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.046s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17127,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:44.518975 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:44.530429 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4354,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.531347 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushMRSOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:44.562280 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushMRSOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":104,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":1501,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1649,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:44.562983 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling LogGCOp(a830801c35db4fe9add4f1768021e9d9): free 121459487 bytes of WAL
I20260812 06:19:44.563210 21876 log_reader.cc:385] T a830801c35db4fe9add4f1768021e9d9: removed 12 log segments from log reader
I20260812 06:19:44.563257 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000003 (ops 11-15)
I20260812 06:19:44.563294 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000004 (ops 16-20)
I20260812 06:19:44.563330 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000005 (ops 21-25)
I20260812 06:19:44.563364 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000006 (ops 26-30)
I20260812 06:19:44.563386 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000007 (ops 31-35)
I20260812 06:19:44.563416 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000008 (ops 36-40)
I20260812 06:19:44.563444 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000009 (ops 41-45)
I20260812 06:19:44.563467 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000010 (ops 46-50)
I20260812 06:19:44.563493 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000011 (ops 51-55)
I20260812 06:19:44.563517 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000012 (ops 56-60)
I20260812 06:19:44.563540 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000013 (ops 61-65)
I20260812 06:19:44.563562 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000014 (ops 66-70)
I20260812 06:19:44.598678 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: LogGCOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.036s	user 0.000s	sys 0.035s Metrics: {}
I20260812 06:19:44.599327 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling UndoDeltaBlockGCOp(a830801c35db4fe9add4f1768021e9d9): 482 bytes on disk
I20260812 06:19:44.599838 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: UndoDeltaBlockGCOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:19:44.600450 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:44.632442 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.032s	user 0.013s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4708,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.632922 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling LogGCOp(a830801c35db4fe9add4f1768021e9d9): free 11564875 bytes of WAL
I20260812 06:19:44.633160 21876 log_reader.cc:385] T a830801c35db4fe9add4f1768021e9d9: removed 1 log segments from log reader
I20260812 06:19:44.633220 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000015 (ops 71-74)
I20260812 06:19:44.635710 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: LogGCOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:44.636059 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:44.647316 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4338,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.647825 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:44.866910 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.219s	user 0.149s	sys 0.070s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877337,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":394,"lbm_read_time_us":16125,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37539,"lbm_writes_lt_1ms":643,"mutex_wait_us":55,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17280,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:19:44.867707 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=14.095187
I20260812 06:19:44.939352 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.069s	user 0.032s	sys 0.035s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25258,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.940073 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=3.181125
I20260812 06:19:44.959465 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.019s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4553930,"delete_count":0,"lbm_write_time_us":7835,"lbm_writes_lt_1ms":114,"reinsert_count":0,"update_count":555}
I20260812 06:19:44.959995 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:44.974407 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.014s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":5474,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:19:44.975008 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:45.218035 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.243s	user 0.132s	sys 0.098s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877213,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":235,"lbm_read_time_us":16840,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37043,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3000}
I20260812 06:19:45.218672 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=18.063937
I20260812 06:19:45.295506 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.077s	user 0.037s	sys 0.029s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":30429,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:45.296027 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:45.307969 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4399,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.308601 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:45.527338 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.219s	user 0.158s	sys 0.050s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":275,"lbm_read_time_us":15588,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34062,"lbm_writes_lt_1ms":643,"mutex_wait_us":49,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":25728,"update_count":3000}
I20260812 06:19:45.528141 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=18.063937
I20260812 06:19:45.599243 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.071s	user 0.039s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":27530,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:45.599814 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:45.611743 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4348,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.612260 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:45.811798 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.199s	user 0.144s	sys 0.055s 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":975,"lbm_read_time_us":15927,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31200,"lbm_writes_lt_1ms":643,"mutex_wait_us":84,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":3000}
I20260812 06:19:45.812575 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=14.095187
I20260812 06:19:45.875413 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.063s	user 0.036s	sys 0.025s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":31724,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:45.875927 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:45.899077 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.023s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6064,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.899539 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:45.911716 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4998,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.912228 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:46.128798 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.216s	user 0.153s	sys 0.063s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877222,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":461,"lbm_read_time_us":17187,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35225,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":3000}
I20260812 06:19:46.129585 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=14.095187
I20260812 06:19:46.178874 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.049s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23024,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:46.179394 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:46.192382 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5061,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.193029 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushMRSOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:46.223757 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushMRSOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.030s	user 0.028s	sys 0.001s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1315,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1779,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:46.224699 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling LogGCOp(a830801c35db4fe9add4f1768021e9d9): free 121459519 bytes of WAL
I20260812 06:19:46.224979 21876 log_reader.cc:385] T a830801c35db4fe9add4f1768021e9d9: removed 12 log segments from log reader
I20260812 06:19:46.225051 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000016 (ops 75-79)
I20260812 06:19:46.225106 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000017 (ops 80-84)
I20260812 06:19:46.225167 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000018 (ops 85-89)
I20260812 06:19:46.225209 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000019 (ops 90-94)
I20260812 06:19:46.225246 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000020 (ops 95-99)
I20260812 06:19:46.225287 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000021 (ops 100-104)
I20260812 06:19:46.225327 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000022 (ops 105-109)
I20260812 06:19:46.225360 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000023 (ops 110-114)
I20260812 06:19:46.225397 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000024 (ops 115-119)
I20260812 06:19:46.225436 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000025 (ops 120-124)
I20260812 06:19:46.225477 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000026 (ops 125-129)
I20260812 06:19:46.225517 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000027 (ops 130-134)
I20260812 06:19:46.256875 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: LogGCOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:19:46.257457 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling UndoDeltaBlockGCOp(a830801c35db4fe9add4f1768021e9d9): 483 bytes on disk
I20260812 06:19:46.258204 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: UndoDeltaBlockGCOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:19:46.259017 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=6.157687
I20260812 06:19:46.285094 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.026s	user 0.009s	sys 0.013s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10854,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:46.285646 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:46.522292 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.236s	user 0.139s	sys 0.096s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979631,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":520,"lbm_read_time_us":16787,"lbm_reads_lt_1ms":769,"lbm_write_time_us":41776,"lbm_writes_lt_1ms":743,"mutex_wait_us":1413,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17152,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:19:46.522974 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=18.063937
I20260812 06:19:46.582347 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.059s	user 0.029s	sys 0.027s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26452,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:46.582983 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:46.605782 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.023s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5495,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.606271 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:46.617537 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4354,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.618340 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:46.806437 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.188s	user 0.156s	sys 0.031s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979633,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":212,"lbm_read_time_us":13641,"lbm_reads_lt_1ms":773,"lbm_write_time_us":39076,"lbm_writes_lt_1ms":743,"mutex_wait_us":107,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":3500}
I20260812 06:19:46.807037 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=14.095187
I20260812 06:19:46.851078 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.044s	user 0.028s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19283,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:46.851675 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:46.867367 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.016s	user 0.000s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5381,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.867859 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:47.043951 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.176s	user 0.113s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":231,"lbm_read_time_us":9259,"lbm_reads_lt_1ms":568,"lbm_write_time_us":32847,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2500}
I20260812 06:19:47.044567 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=14.095187
I20260812 06:19:47.105082 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.060s	user 0.044s	sys 0.009s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25343,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.105604 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:47.259864 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.154s	user 0.102s	sys 0.052s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":609,"lbm_read_time_us":10483,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24069,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:19:47.260645 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=14.095187
I20260812 06:19:47.313015 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.052s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20305,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.313639 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:47.326632 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4408,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.327298 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:47.523108 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.196s	user 0.126s	sys 0.063s 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":829,"lbm_read_time_us":12668,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31090,"lbm_writes_lt_1ms":543,"mutex_wait_us":269,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:19:47.527271 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=14.095187
I20260812 06:19:47.582564 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.055s	user 0.037s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25766,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.583359 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:47.598057 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5672,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.598630 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushMRSOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:47.659016 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushMRSOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.060s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":284,"dirs.run_wall_time_us":1507,"drs_written":1,"lbm_read_time_us":106,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1994,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:47.659714 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling LogGCOp(a830801c35db4fe9add4f1768021e9d9): free 120100575 bytes of WAL
I20260812 06:19:47.659960 21876 log_reader.cc:385] T a830801c35db4fe9add4f1768021e9d9: removed 12 log segments from log reader
I20260812 06:19:47.660006 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000028 (ops 135-138)
I20260812 06:19:47.660036 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000029 (ops 139-143)
I20260812 06:19:47.660099 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000030 (ops 144-148)
I20260812 06:19:47.660146 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000031 (ops 149-152)
I20260812 06:19:47.660187 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000032 (ops 153-157)
I20260812 06:19:47.660245 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000033 (ops 158-162)
I20260812 06:19:47.660296 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000034 (ops 163-166)
I20260812 06:19:47.660342 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000035 (ops 167-171)
I20260812 06:19:47.660384 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000036 (ops 172-176)
I20260812 06:19:47.660424 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000037 (ops 177-181)
I20260812 06:19:47.660465 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000038 (ops 182-186)
I20260812 06:19:47.660504 21876 log.cc:1079] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: Deleting log segment in path: /tmp/dist-test-task16oi43/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576839729-21559-0/minicluster-data/ts-0-root/wals/a830801c35db4fe9add4f1768021e9d9/wal-000000039 (ops 187-191)
I20260812 06:19:47.688486 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: LogGCOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:47.688958 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling UndoDeltaBlockGCOp(a830801c35db4fe9add4f1768021e9d9): 462 bytes on disk
I20260812 06:19:47.689407 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: UndoDeltaBlockGCOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:19:47.689953 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=7.149875
I20260812 06:19:47.711413 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.021s	user 0.009s	sys 0.011s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9389,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:47.711889 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=2.188937
I20260812 06:19:47.722360 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3990,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:47.723239 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9): perf score=1.000000
I20260812 06:19:47.870839 21559 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.059s	user 1.833s	sys 0.194s
I20260812 06:19:47.985281 21559 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.114s	user 0.007s	sys 0.000s
I20260812 06:19:47.985561 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: MajorDeltaCompactionOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.262s	user 0.158s	sys 0.104s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082155,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":193,"lbm_read_time_us":20202,"lbm_reads_lt_1ms":870,"lbm_write_time_us":38987,"lbm_writes_lt_1ms":843,"mutex_wait_us":92,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":81280,"thread_start_us":110,"threads_started":1,"update_count":4000}
I20260812 06:19:47.985976 21559 tablet_server.cc:179] TabletServer@127.21.13.193:0 shutting down...
I20260812 06:19:47.988891 21942 maintenance_manager.cc:419] P 7cf7a83e9d6c4c2099f546294c9e4477: Scheduling FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9): perf score=10.126437
I20260812 06:19:48.021154 21876 maintenance_manager.cc:643] P 7cf7a83e9d6c4c2099f546294c9e4477: FlushDeltaMemStoresOp(a830801c35db4fe9add4f1768021e9d9) complete. Timing: real 0.032s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14456,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:48.021765 21559 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:48.022009 21559 tablet_replica.cc:333] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477: stopping tablet replica
I20260812 06:19:48.022159 21559 raft_consensus.cc:2243] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:48.022495 21559 raft_consensus.cc:2272] T a830801c35db4fe9add4f1768021e9d9 P 7cf7a83e9d6c4c2099f546294c9e4477 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:48.026492 21559 tablet_server.cc:196] TabletServer@127.21.13.193:0 shutdown complete.
I20260812 06:19:48.057518 21559 master.cc:562] Master@127.21.13.254:44109 shutting down...
I20260812 06:19:48.061859 21559 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:48.062077 21559 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:48.062171 21559 tablet_replica.cc:333] T 00000000000000000000000000000000 P f10a780380a94dffa7fc59d4bdf08f6f: stopping tablet replica
I20260812 06:19:48.074941 21559 master.cc:584] Master@127.21.13.254:44109 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5587 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11319 ms total)

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