[==========] 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:18:22.949633 22120 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.154.62:35347
I20260812 06:18:22.950697 22120 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:18:22.951500 22120 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:22.958281 22129 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:18:22.958636 22135 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:18:22.958745 22120 server_base.cc:1061] running on GCE node
W20260812 06:18:22.958814 22132 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:18:22.959278 22120 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:22.959365 22120 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:18:22.959398 22120 hybrid_clock.cc:648] HybridClock initialized: now 1786515502959397 us; error 0 us; skew 500 ppm
I20260812 06:18:22.961267 22120 webserver.cc:533] Webserver started at http://127.21.154.62:35309/ using document root <none> and password file <none>
I20260812 06:18:22.961750 22120 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:22.961809 22120 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:22.961990 22120 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:22.963624 22120 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/master-0-root/instance:
uuid: "b547995d083346468071bea24c2e4c6d"
format_stamp: "Formatted at 2026-08-12 06:18:22 on dist-test-slave-h6n0"
I20260812 06:18:22.967331 22120 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:22.969802 22142 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:18:22.971362 22120 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:22.971536 22120 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/master-0-root
uuid: "b547995d083346468071bea24c2e4c6d"
format_stamp: "Formatted at 2026-08-12 06:18:22 on dist-test-slave-h6n0"
I20260812 06:18:22.971655 22120 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-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:18:22.980453 22120 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:22.981009 22120 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:18:22.981178 22120 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:22.989030 22120 rpc_server.cc:307] RPC server started. Bound to: 127.21.154.62:35347
I20260812 06:18:22.989100 22239 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.154.62:35347 every 8 connection(s)
I20260812 06:18:22.991381 22241 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:18:22.996610 22241 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d: Bootstrap starting.
I20260812 06:18:22.999956 22241 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:23.000908 22241 log.cc:826] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:23.002734 22241 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d: No bootstrap required, opened a new log
I20260812 06:18:23.005633 22241 raft_consensus.cc:359] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b547995d083346468071bea24c2e4c6d" member_type: VOTER }
I20260812 06:18:23.005805 22241 raft_consensus.cc:385] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:23.005858 22241 raft_consensus.cc:740] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b547995d083346468071bea24c2e4c6d, State: Initialized, Role: FOLLOWER
I20260812 06:18:23.006493 22241 consensus_queue.cc:260] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [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: "b547995d083346468071bea24c2e4c6d" member_type: VOTER }
I20260812 06:18:23.006718 22241 raft_consensus.cc:399] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:23.006776 22241 raft_consensus.cc:493] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:23.006875 22241 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:23.007655 22241 raft_consensus.cc:515] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b547995d083346468071bea24c2e4c6d" member_type: VOTER }
I20260812 06:18:23.008078 22241 leader_election.cc:304] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [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: b547995d083346468071bea24c2e4c6d; no voters: 
I20260812 06:18:23.008368 22241 leader_election.cc:290] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:23.008538 22248 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:23.008803 22248 raft_consensus.cc:697] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [term 1 LEADER]: Becoming Leader. State: Replica: b547995d083346468071bea24c2e4c6d, State: Running, Role: LEADER
I20260812 06:18:23.009227 22248 consensus_queue.cc:237] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [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: "b547995d083346468071bea24c2e4c6d" member_type: VOTER }
I20260812 06:18:23.009537 22241 sys_catalog.cc:565] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:23.011198 22250 sys_catalog.cc:455] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [sys.catalog]: SysCatalogTable state changed. Reason: New leader b547995d083346468071bea24c2e4c6d. Latest consensus state: current_term: 1 leader_uuid: "b547995d083346468071bea24c2e4c6d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b547995d083346468071bea24c2e4c6d" member_type: VOTER } }
I20260812 06:18:23.011236 22249 sys_catalog.cc:455] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b547995d083346468071bea24c2e4c6d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b547995d083346468071bea24c2e4c6d" member_type: VOTER } }
I20260812 06:18:23.011344 22250 sys_catalog.cc:458] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:23.011353 22249 sys_catalog.cc:458] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:23.011683 22266 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:23.013808 22266 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:23.014115 22120 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:23.018213 22266 catalog_manager.cc:1383] Generated new cluster ID: 6687b27c028146489a3bdf3aabbe80fd
I20260812 06:18:23.018275 22266 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:23.027343 22266 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:23.028542 22266 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:23.038326 22266 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d: Generated new TSK 0
I20260812 06:18:23.039095 22266 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:23.046691 22120 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:23.049299 22284 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:18:23.049412 22289 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:18:23.049592 22286 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:18:23.049757 22120 server_base.cc:1061] running on GCE node
I20260812 06:18:23.049965 22120 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:23.050005 22120 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:18:23.050041 22120 hybrid_clock.cc:648] HybridClock initialized: now 1786515503050041 us; error 0 us; skew 500 ppm
I20260812 06:18:23.051124 22120 webserver.cc:533] Webserver started at http://127.21.154.1:34465/ using document root <none> and password file <none>
I20260812 06:18:23.051293 22120 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:23.051360 22120 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:23.051440 22120 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:23.051884 22120 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/instance:
uuid: "cce789e38b9c4accaf8a0e17d2897524"
format_stamp: "Formatted at 2026-08-12 06:18:23 on dist-test-slave-h6n0"
I20260812 06:18:23.053712 22120 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:23.055176 22297 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:18:23.055585 22120 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:23.055656 22120 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root
uuid: "cce789e38b9c4accaf8a0e17d2897524"
format_stamp: "Formatted at 2026-08-12 06:18:23 on dist-test-slave-h6n0"
I20260812 06:18:23.055749 22120 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-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:18:23.065843 22120 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:23.066303 22120 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:23.066887 22120 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:23.067790 22120 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:23.067840 22120 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:23.067930 22120 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:23.067970 22120 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:23.075521 22120 rpc_server.cc:307] RPC server started. Bound to: 127.21.154.1:34981
I20260812 06:18:23.075582 22399 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.154.1:34981 every 8 connection(s)
I20260812 06:18:23.087749 22400 heartbeater.cc:344] Connected to a master server at 127.21.154.62:35347
I20260812 06:18:23.088073 22400 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:23.088622 22400 heartbeater.cc:507] Master 127.21.154.62:35347 requested a full tablet report, sending...
I20260812 06:18:23.090772 22173 ts_manager.cc:194] Registered new tserver with Master: cce789e38b9c4accaf8a0e17d2897524 (127.21.154.1:34981)
I20260812 06:18:23.091398 22120 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014891986s
I20260812 06:18:23.092707 22173 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48470
I20260812 06:18:23.102869 22173 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48472:
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:18:23.117825 22338 tablet_service.cc:1511] Processing CreateTablet for tablet 8d3acdd7bfe4494a8c687a299efc72f6 (DEFAULT_TABLE table=heavy-update-compaction-test [id=315e160b8c944796bd6eb94ea57e8e54]), partition=
I20260812 06:18:23.118307 22338 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8d3acdd7bfe4494a8c687a299efc72f6. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:23.121304 22418 tablet_bootstrap.cc:492] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Bootstrap starting.
I20260812 06:18:23.122342 22418 tablet_bootstrap.cc:654] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:23.123525 22418 tablet_bootstrap.cc:492] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: No bootstrap required, opened a new log
I20260812 06:18:23.123641 22418 ts_tablet_manager.cc:1403] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:23.124094 22418 raft_consensus.cc:359] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cce789e38b9c4accaf8a0e17d2897524" member_type: VOTER last_known_addr { host: "127.21.154.1" port: 34981 } }
I20260812 06:18:23.124191 22418 raft_consensus.cc:385] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:23.124215 22418 raft_consensus.cc:740] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: cce789e38b9c4accaf8a0e17d2897524, State: Initialized, Role: FOLLOWER
I20260812 06:18:23.124401 22418 consensus_queue.cc:260] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524 [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: "cce789e38b9c4accaf8a0e17d2897524" member_type: VOTER last_known_addr { host: "127.21.154.1" port: 34981 } }
I20260812 06:18:23.124503 22418 raft_consensus.cc:399] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:23.124565 22418 raft_consensus.cc:493] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:23.124642 22418 raft_consensus.cc:3060] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:23.125391 22418 raft_consensus.cc:515] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cce789e38b9c4accaf8a0e17d2897524" member_type: VOTER last_known_addr { host: "127.21.154.1" port: 34981 } }
I20260812 06:18:23.125545 22418 leader_election.cc:304] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524 [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: cce789e38b9c4accaf8a0e17d2897524; no voters: 
I20260812 06:18:23.125783 22418 leader_election.cc:290] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:23.125860 22420 raft_consensus.cc:2804] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:23.126048 22420 raft_consensus.cc:697] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524 [term 1 LEADER]: Becoming Leader. State: Replica: cce789e38b9c4accaf8a0e17d2897524, State: Running, Role: LEADER
I20260812 06:18:23.126133 22418 ts_tablet_manager.cc:1434] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:23.126199 22420 consensus_queue.cc:237] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524 [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: "cce789e38b9c4accaf8a0e17d2897524" member_type: VOTER last_known_addr { host: "127.21.154.1" port: 34981 } }
I20260812 06:18:23.126518 22400 heartbeater.cc:499] Master 127.21.154.62:35347 was elected leader, sending a full tablet report...
I20260812 06:18:23.129170 22173 catalog_manager.cc:5719] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524 reported cstate change: term changed from 0 to 1, leader changed from <none> to cce789e38b9c4accaf8a0e17d2897524 (127.21.154.1). New cstate: current_term: 1 leader_uuid: "cce789e38b9c4accaf8a0e17d2897524" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cce789e38b9c4accaf8a0e17d2897524" member_type: VOTER last_known_addr { host: "127.21.154.1" port: 34981 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:23.199615 22120 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.060s	user 0.018s	sys 0.009s
I20260812 06:18:23.327280 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushMRSOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=15.086190
I20260812 06:18:23.466961 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushMRSOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.139s	user 0.098s	sys 0.041s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":291,"delete_count":0,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":721,"drs_written":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4,"lbm_write_time_us":32468,"lbm_writes_lt_1ms":567,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":145,"threads_started":1,"update_count":1050}
I20260812 06:18:23.467991 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling LogGCOp(8d3acdd7bfe4494a8c687a299efc72f6): free 8725963 bytes of WAL
I20260812 06:18:23.468292 22303 log_reader.cc:385] T 8d3acdd7bfe4494a8c687a299efc72f6: removed 1 log segments from log reader
I20260812 06:18:23.468370 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000001 (ops 1-6)
I20260812 06:18:23.470242 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: LogGCOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:23.470597 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling UndoDeltaBlockGCOp(8d3acdd7bfe4494a8c687a299efc72f6): 12308958 bytes on disk
I20260812 06:18:23.471107 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: UndoDeltaBlockGCOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:23.471451 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:23.485189 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4978,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:23.485911 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:23.608237 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.122s	user 0.101s	sys 0.019s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":994,"lbm_read_time_us":8216,"lbm_reads_lt_1ms":360,"lbm_write_time_us":21778,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":373,"threads_started":5,"update_count":1500}
I20260812 06:18:23.608809 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=7.149875
I20260812 06:18:23.636384 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.027s	user 0.017s	sys 0.008s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11929,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:23.636921 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:23.647717 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3810,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:23.648222 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:23.769078 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.121s	user 0.100s	sys 0.012s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":620,"lbm_read_time_us":8121,"lbm_reads_lt_1ms":372,"lbm_write_time_us":20460,"lbm_writes_lt_1ms":343,"mutex_wait_us":314,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":1500}
I20260812 06:18:23.769981 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=10.126437
I20260812 06:18:23.802886 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.033s	user 0.025s	sys 0.007s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14650,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:23.803531 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:23.913288 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.110s	user 0.101s	sys 0.004s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528780,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":789,"lbm_read_time_us":7100,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20938,"lbm_writes_lt_1ms":343,"mutex_wait_us":50,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":1500}
I20260812 06:18:23.914006 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=10.126437
I20260812 06:18:23.963317 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.049s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16803,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:23.963864 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:23.976122 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.012s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4006,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.976871 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:24.110745 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.134s	user 0.098s	sys 0.032s 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":284,"lbm_read_time_us":8139,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27192,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.111389 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=10.126437
I20260812 06:18:24.165470 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.054s	user 0.018s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17601,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:24.165939 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:24.177333 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.011s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4067,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.177812 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:24.332998 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.155s	user 0.106s	sys 0.043s 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":218,"lbm_read_time_us":10455,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24302,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20736,"update_count":2000}
I20260812 06:18:24.333670 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=10.126437
I20260812 06:18:24.388581 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.055s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22492,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:24.389328 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:24.401134 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4200,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.402123 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:24.541980 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.140s	user 0.108s	sys 0.032s 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":278,"lbm_read_time_us":11193,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25834,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:24.542699 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=10.126437
I20260812 06:18:24.588294 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.045s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15812,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:24.588753 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:24.602114 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4654,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.602662 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:24.720778 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.118s	user 0.101s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":661,"lbm_read_time_us":7179,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23553,"lbm_writes_lt_1ms":443,"mutex_wait_us":64,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2000}
I20260812 06:18:24.721659 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=10.126437
I20260812 06:18:24.779407 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.058s	user 0.030s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16461,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:24.780073 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:24.791783 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4845,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.792398 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushMRSOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:24.842029 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushMRSOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.049s	user 0.039s	sys 0.000s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":1160,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2068,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:24.843255 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling LogGCOp(8d3acdd7bfe4494a8c687a299efc72f6): free 127961091 bytes of WAL
I20260812 06:18:24.843550 22303 log_reader.cc:385] T 8d3acdd7bfe4494a8c687a299efc72f6: removed 12 log segments from log reader
I20260812 06:18:24.843603 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000002 (ops 7-11)
I20260812 06:18:24.843638 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000003 (ops 12-16)
I20260812 06:18:24.843709 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000004 (ops 17-21)
I20260812 06:18:24.843760 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000005 (ops 22-26)
I20260812 06:18:24.843819 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000006 (ops 27-31)
I20260812 06:18:24.843866 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000007 (ops 32-36)
I20260812 06:18:24.843935 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000008 (ops 37-41)
I20260812 06:18:24.843966 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000009 (ops 42-46)
I20260812 06:18:24.844008 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000010 (ops 47-51)
I20260812 06:18:24.844033 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000011 (ops 52-56)
I20260812 06:18:24.844059 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000012 (ops 57-61)
I20260812 06:18:24.844076 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000013 (ops 62-66)
I20260812 06:18:24.876161 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: LogGCOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.033s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:18:24.876748 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling UndoDeltaBlockGCOp(8d3acdd7bfe4494a8c687a299efc72f6): 462 bytes on disk
I20260812 06:18:24.877296 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: UndoDeltaBlockGCOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:18:24.878064 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=3.181125
I20260812 06:18:24.893590 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4923146,"delete_count":0,"lbm_write_time_us":6117,"lbm_writes_lt_1ms":123,"reinsert_count":0,"update_count":600}
I20260812 06:18:24.894147 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:24.908113 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3282155,"delete_count":0,"lbm_write_time_us":5244,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:18:24.908754 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:25.118835 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.210s	user 0.125s	sys 0.084s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836356,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":568,"lbm_read_time_us":13206,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36029,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":21120,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:18:25.119714 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=14.095187
I20260812 06:18:25.188194 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.068s	user 0.040s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":26260,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.188772 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:25.205315 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6227,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.206064 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:25.388916 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.182s	user 0.119s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":148,"lbm_read_time_us":13386,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30545,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:18:25.389578 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=14.095187
I20260812 06:18:25.451355 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.062s	user 0.027s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21651,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.451953 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:25.471405 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.019s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7699,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.472222 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:25.657796 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.185s	user 0.153s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":355,"lbm_read_time_us":13319,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30417,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:25.658434 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=14.095187
I20260812 06:18:25.727546 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.069s	user 0.040s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28668,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.728179 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:25.739380 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4452,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.739787 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:25.927130 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.187s	user 0.134s	sys 0.047s 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":273,"lbm_read_time_us":13067,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30655,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19456,"update_count":2500}
I20260812 06:18:25.927886 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=14.095187
I20260812 06:18:25.979857 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.052s	user 0.019s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23085,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.980428 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:26.008424 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.028s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7216,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.008908 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:26.188621 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.180s	user 0.103s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":842,"lbm_read_time_us":12131,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31247,"lbm_writes_lt_1ms":543,"mutex_wait_us":239,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:26.189271 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=14.095187
I20260812 06:18:26.242019 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.053s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":23222,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.242690 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:26.282147 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.039s	user 0.004s	sys 0.018s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5662,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.282953 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:26.294667 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4620,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.295167 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushMRSOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:26.337857 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushMRSOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.043s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":156,"dirs.run_cpu_time_us":341,"dirs.run_wall_time_us":1200,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1996,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:26.339061 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling LogGCOp(8d3acdd7bfe4494a8c687a299efc72f6): free 112692325 bytes of WAL
I20260812 06:18:26.339545 22303 log_reader.cc:385] T 8d3acdd7bfe4494a8c687a299efc72f6: removed 11 log segments from log reader
I20260812 06:18:26.339666 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000014 (ops 67-71)
I20260812 06:18:26.339746 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000015 (ops 72-76)
I20260812 06:18:26.339814 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000016 (ops 77-81)
I20260812 06:18:26.339861 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000017 (ops 82-86)
I20260812 06:18:26.339901 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000018 (ops 87-91)
I20260812 06:18:26.339942 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000019 (ops 92-96)
I20260812 06:18:26.339980 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000020 (ops 97-101)
I20260812 06:18:26.340021 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000021 (ops 102-106)
I20260812 06:18:26.340107 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000022 (ops 107-111)
I20260812 06:18:26.340174 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000023 (ops 112-116)
I20260812 06:18:26.340212 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000024 (ops 117-121)
I20260812 06:18:26.368333 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: LogGCOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:26.368829 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling UndoDeltaBlockGCOp(8d3acdd7bfe4494a8c687a299efc72f6): 448 bytes on disk
I20260812 06:18:26.369393 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: UndoDeltaBlockGCOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:18:26.370338 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:26.392964 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.022s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6911,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.393388 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:26.404003 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4256,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.404438 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:26.671228 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.267s	user 0.178s	sys 0.081s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37041321,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":818,"lbm_read_time_us":18288,"lbm_reads_lt_1ms":875,"lbm_write_time_us":47890,"lbm_writes_lt_1ms":843,"mutex_wait_us":3,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":8704,"thread_start_us":82,"threads_started":1,"update_count":4000}
I20260812 06:18:26.672163 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=18.063937
I20260812 06:18:26.749078 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.077s	user 0.046s	sys 0.028s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":34125,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:18:26.749675 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:26.776640 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.027s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6371,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.777148 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:26.792424 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.792903 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:26.979889 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.187s	user 0.161s	sys 0.025s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32938667,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":614,"lbm_read_time_us":13561,"lbm_reads_lt_1ms":773,"lbm_write_time_us":41136,"lbm_writes_lt_1ms":743,"mutex_wait_us":88,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":3500}
I20260812 06:18:26.980486 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=14.095187
I20260812 06:18:27.027298 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.046s	user 0.038s	sys 0.007s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":20400,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:27.028369 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:27.039184 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4140,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.040001 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:27.198024 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.158s	user 0.123s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733720,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":354,"lbm_read_time_us":11410,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30494,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:27.198904 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=12.110812
I20260812 06:18:27.239005 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.040s	user 0.023s	sys 0.016s Metrics: {"bytes_written":13661282,"delete_count":0,"lbm_write_time_us":17676,"lbm_writes_lt_1ms":336,"reinsert_count":0,"update_count":1665}
I20260812 06:18:27.239728 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.196750
I20260812 06:18:27.249872 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3159084,"delete_count":0,"lbm_write_time_us":3800,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:18:27.250360 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:27.394227 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.144s	user 0.079s	sys 0.052s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21041529,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":159,"lbm_read_time_us":9165,"lbm_reads_lt_1ms":474,"lbm_write_time_us":24080,"lbm_writes_lt_1ms":453,"mutex_wait_us":22,"peak_mem_usage":51099678,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2050}
I20260812 06:18:27.394984 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=14.095187
I20260812 06:18:27.448468 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.052s	user 0.025s	sys 0.024s Metrics: {"bytes_written":15999660,"delete_count":0,"lbm_write_time_us":22975,"lbm_writes_lt_1ms":393,"reinsert_count":0,"update_count":1950}
I20260812 06:18:27.448995 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:27.473958 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.025s	user 0.007s	sys 0.014s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7118,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.474910 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:27.651448 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.176s	user 0.112s	sys 0.057s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24323481,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":622,"lbm_read_time_us":11505,"lbm_reads_lt_1ms":554,"lbm_write_time_us":30144,"lbm_writes_lt_1ms":533,"mutex_wait_us":44,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2450}
I20260812 06:18:27.651917 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=14.095187
I20260812 06:18:27.709071 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.057s	user 0.033s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21442,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.709718 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:27.725466 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6134,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.725916 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushMRSOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:27.754315 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushMRSOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.028s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1169,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1494,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:27.755380 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:27.772213 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6744,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.772902 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling LogGCOp(8d3acdd7bfe4494a8c687a299efc72f6): free 112239526 bytes of WAL
I20260812 06:18:27.773229 22303 log_reader.cc:385] T 8d3acdd7bfe4494a8c687a299efc72f6: removed 11 log segments from log reader
I20260812 06:18:27.773337 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000025 (ops 122-126)
I20260812 06:18:27.773427 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000026 (ops 127-131)
I20260812 06:18:27.773518 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000027 (ops 132-136)
I20260812 06:18:27.773597 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000028 (ops 137-140)
I20260812 06:18:27.773650 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000029 (ops 141-145)
I20260812 06:18:27.773713 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000030 (ops 146-150)
I20260812 06:18:27.773778 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000031 (ops 151-155)
I20260812 06:18:27.773859 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000032 (ops 156-160)
I20260812 06:18:27.773936 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000033 (ops 161-165)
I20260812 06:18:27.774041 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000034 (ops 166-170)
I20260812 06:18:27.774147 22303 log.cc:1079] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/8d3acdd7bfe4494a8c687a299efc72f6/wal-000000035 (ops 171-175)
I20260812 06:18:27.801505 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: LogGCOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:27.801975 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:27.991065 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.189s	user 0.139s	sys 0.048s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836256,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2294,"lbm_read_time_us":11732,"lbm_reads_lt_1ms":665,"lbm_write_time_us":35382,"lbm_writes_lt_1ms":643,"mutex_wait_us":1737,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13952,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:18:27.991705 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling UndoDeltaBlockGCOp(8d3acdd7bfe4494a8c687a299efc72f6): 447 bytes on disk
I20260812 06:18:27.992168 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: UndoDeltaBlockGCOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4}
I20260812 06:18:27.993073 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=14.095187
I20260812 06:18:28.054303 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.061s	user 0.035s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22290,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.054930 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:28.071439 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.016s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.071982 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:28.256191 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.184s	user 0.120s	sys 0.064s 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":1075,"lbm_read_time_us":12995,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32371,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:18:28.256918 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=11.118625
I20260812 06:18:28.302145 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.045s	user 0.030s	sys 0.012s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":19190,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:28.302750 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=2.188937
I20260812 06:18:28.316104 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5301,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:28.316558 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=1.000000
I20260812 06:18:28.401258 22120 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.202s	user 1.929s	sys 0.159s
I20260812 06:18:28.459281 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: MajorDeltaCompactionOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.143s	user 0.086s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631306,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":118,"lbm_read_time_us":8654,"lbm_reads_lt_1ms":468,"lbm_write_time_us":29976,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":2000}
I20260812 06:18:28.460091 22402 maintenance_manager.cc:419] P cce789e38b9c4accaf8a0e17d2897524: Scheduling FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6): perf score=6.157687
I20260812 06:18:28.465597 22120 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.064s	user 0.002s	sys 0.000s
I20260812 06:18:28.466673 22120 tablet_server.cc:179] TabletServer@127.21.154.1:0 shutting down...
I20260812 06:18:28.483568 22303 maintenance_manager.cc:643] P cce789e38b9c4accaf8a0e17d2897524: FlushDeltaMemStoresOp(8d3acdd7bfe4494a8c687a299efc72f6) complete. Timing: real 0.023s	user 0.009s	sys 0.013s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9889,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:28.484562 22120 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:28.485101 22120 tablet_replica.cc:333] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524: stopping tablet replica
I20260812 06:18:28.485359 22120 raft_consensus.cc:2243] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:28.485656 22120 raft_consensus.cc:2272] T 8d3acdd7bfe4494a8c687a299efc72f6 P cce789e38b9c4accaf8a0e17d2897524 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:28.506285 22120 tablet_server.cc:196] TabletServer@127.21.154.1:0 shutdown complete.
I20260812 06:18:28.511965 22120 master.cc:562] Master@127.21.154.62:35347 shutting down...
I20260812 06:18:28.516448 22120 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:28.516770 22120 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:28.516920 22120 tablet_replica.cc:333] T 00000000000000000000000000000000 P b547995d083346468071bea24c2e4c6d: stopping tablet replica
I20260812 06:18:28.529717 22120 master.cc:584] Master@127.21.154.62:35347 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5674 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:28.623337 22120 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.154.62:44443
I20260812 06:18:28.623751 22120 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:28.625905 22457 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:18:28.625919 22455 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:18:28.626273 22454 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:18:28.626451 22120 server_base.cc:1061] running on GCE node
I20260812 06:18:28.626642 22120 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:28.626715 22120 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:18:28.626757 22120 hybrid_clock.cc:648] HybridClock initialized: now 1786515508626757 us; error 0 us; skew 500 ppm
I20260812 06:18:28.627627 22120 webserver.cc:533] Webserver started at http://127.21.154.62:43041/ using document root <none> and password file <none>
I20260812 06:18:28.627758 22120 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:28.627790 22120 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:28.627849 22120 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:28.628257 22120 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/master-0-root/instance:
uuid: "7b4d52ab167542de9a20a36d5885b63c"
format_stamp: "Formatted at 2026-08-12 06:18:28 on dist-test-slave-h6n0"
I20260812 06:18:28.629840 22120 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:28.631240 22467 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:18:28.631742 22120 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:28.631943 22120 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/master-0-root
uuid: "7b4d52ab167542de9a20a36d5885b63c"
format_stamp: "Formatted at 2026-08-12 06:18:28 on dist-test-slave-h6n0"
I20260812 06:18:28.632121 22120 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-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:18:28.637463 22120 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:28.637812 22120 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:28.643672 22120 rpc_server.cc:307] RPC server started. Bound to: 127.21.154.62:44443
I20260812 06:18:28.646253 22533 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.154.62:44443 every 8 connection(s)
I20260812 06:18:28.646512 22535 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:18:28.663256 22535 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c: Bootstrap starting.
I20260812 06:18:28.664129 22535 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:28.665478 22535 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c: No bootstrap required, opened a new log
I20260812 06:18:28.665915 22535 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7b4d52ab167542de9a20a36d5885b63c" member_type: VOTER }
I20260812 06:18:28.666006 22535 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:28.666033 22535 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7b4d52ab167542de9a20a36d5885b63c, State: Initialized, Role: FOLLOWER
I20260812 06:18:28.666199 22535 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [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: "7b4d52ab167542de9a20a36d5885b63c" member_type: VOTER }
I20260812 06:18:28.666272 22535 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:28.666332 22535 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:28.666396 22535 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:28.667183 22535 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7b4d52ab167542de9a20a36d5885b63c" member_type: VOTER }
I20260812 06:18:28.667294 22535 leader_election.cc:304] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [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: 7b4d52ab167542de9a20a36d5885b63c; no voters: 
I20260812 06:18:28.667558 22535 leader_election.cc:290] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:28.667719 22542 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:28.668015 22535 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:28.668138 22542 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [term 1 LEADER]: Becoming Leader. State: Replica: 7b4d52ab167542de9a20a36d5885b63c, State: Running, Role: LEADER
I20260812 06:18:28.668347 22542 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [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: "7b4d52ab167542de9a20a36d5885b63c" member_type: VOTER }
I20260812 06:18:28.668825 22544 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7b4d52ab167542de9a20a36d5885b63c. Latest consensus state: current_term: 1 leader_uuid: "7b4d52ab167542de9a20a36d5885b63c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7b4d52ab167542de9a20a36d5885b63c" member_type: VOTER } }
I20260812 06:18:28.669006 22544 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:28.669246 22543 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7b4d52ab167542de9a20a36d5885b63c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7b4d52ab167542de9a20a36d5885b63c" member_type: VOTER } }
I20260812 06:18:28.669384 22543 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:28.669395 22552 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:28.670387 22552 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:28.670629 22120 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:28.672353 22552 catalog_manager.cc:1383] Generated new cluster ID: be79600a707f40b390301f8d41478ba3
I20260812 06:18:28.672417 22552 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:28.698081 22552 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:28.698745 22552 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:28.706683 22552 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c: Generated new TSK 0
I20260812 06:18:28.706991 22552 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:28.735697 22120 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:28.737857 22566 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:18:28.737998 22564 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:18:28.738067 22572 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:18:28.738222 22120 server_base.cc:1061] running on GCE node
I20260812 06:18:28.738350 22120 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:28.738385 22120 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:18:28.738427 22120 hybrid_clock.cc:648] HybridClock initialized: now 1786515508738403 us; error 0 us; skew 500 ppm
I20260812 06:18:28.739317 22120 webserver.cc:533] Webserver started at http://127.21.154.1:40119/ using document root <none> and password file <none>
I20260812 06:18:28.739466 22120 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:28.739518 22120 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:28.739586 22120 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:28.739974 22120 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/instance:
uuid: "d46b564460354d17a603ccd98fb8d2db"
format_stamp: "Formatted at 2026-08-12 06:18:28 on dist-test-slave-h6n0"
I20260812 06:18:28.741798 22120 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:28.743100 22581 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:18:28.743533 22120 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:28.743759 22120 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root
uuid: "d46b564460354d17a603ccd98fb8d2db"
format_stamp: "Formatted at 2026-08-12 06:18:28 on dist-test-slave-h6n0"
I20260812 06:18:28.743871 22120 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-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:18:28.757126 22120 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:28.757541 22120 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:28.758064 22120 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:28.758904 22120 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:28.758955 22120 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:28.758993 22120 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:28.759011 22120 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:28.763976 22120 rpc_server.cc:307] RPC server started. Bound to: 127.21.154.1:39483
I20260812 06:18:28.764008 22671 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.154.1:39483 every 8 connection(s)
I20260812 06:18:28.773108 22672 heartbeater.cc:344] Connected to a master server at 127.21.154.62:44443
I20260812 06:18:28.773221 22672 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:28.773480 22672 heartbeater.cc:507] Master 127.21.154.62:44443 requested a full tablet report, sending...
I20260812 06:18:28.774466 22485 ts_manager.cc:194] Registered new tserver with Master: d46b564460354d17a603ccd98fb8d2db (127.21.154.1:39483)
I20260812 06:18:28.774765 22120 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01029561s
I20260812 06:18:28.775655 22485 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36920
I20260812 06:18:28.783995 22485 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36922:
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:18:28.793777 22624 tablet_service.cc:1511] Processing CreateTablet for tablet 320268b5585c4b02a6f7fecffcfbf752 (DEFAULT_TABLE table=heavy-update-compaction-test [id=37b090a64e3543e7b706b85cf125ff12]), partition=
I20260812 06:18:28.794083 22624 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 320268b5585c4b02a6f7fecffcfbf752. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:28.796454 22688 tablet_bootstrap.cc:492] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Bootstrap starting.
I20260812 06:18:28.797348 22688 tablet_bootstrap.cc:654] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:28.798583 22688 tablet_bootstrap.cc:492] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: No bootstrap required, opened a new log
I20260812 06:18:28.798700 22688 ts_tablet_manager.cc:1403] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:28.799165 22688 raft_consensus.cc:359] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d46b564460354d17a603ccd98fb8d2db" member_type: VOTER last_known_addr { host: "127.21.154.1" port: 39483 } }
I20260812 06:18:28.799275 22688 raft_consensus.cc:385] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:28.799322 22688 raft_consensus.cc:740] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d46b564460354d17a603ccd98fb8d2db, State: Initialized, Role: FOLLOWER
I20260812 06:18:28.799470 22688 consensus_queue.cc:260] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db [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: "d46b564460354d17a603ccd98fb8d2db" member_type: VOTER last_known_addr { host: "127.21.154.1" port: 39483 } }
I20260812 06:18:28.799577 22688 raft_consensus.cc:399] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:28.799624 22688 raft_consensus.cc:493] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:28.799676 22688 raft_consensus.cc:3060] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:28.800362 22688 raft_consensus.cc:515] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d46b564460354d17a603ccd98fb8d2db" member_type: VOTER last_known_addr { host: "127.21.154.1" port: 39483 } }
I20260812 06:18:28.800513 22688 leader_election.cc:304] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db [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: d46b564460354d17a603ccd98fb8d2db; no voters: 
I20260812 06:18:28.800717 22688 leader_election.cc:290] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:28.800889 22690 raft_consensus.cc:2804] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:28.801076 22672 heartbeater.cc:499] Master 127.21.154.62:44443 was elected leader, sending a full tablet report...
I20260812 06:18:28.801151 22690 raft_consensus.cc:697] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db [term 1 LEADER]: Becoming Leader. State: Replica: d46b564460354d17a603ccd98fb8d2db, State: Running, Role: LEADER
I20260812 06:18:28.801350 22688 ts_tablet_manager.cc:1434] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Time spent starting tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:28.801338 22690 consensus_queue.cc:237] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db [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: "d46b564460354d17a603ccd98fb8d2db" member_type: VOTER last_known_addr { host: "127.21.154.1" port: 39483 } }
I20260812 06:18:28.802708 22485 catalog_manager.cc:5719] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db reported cstate change: term changed from 0 to 1, leader changed from <none> to d46b564460354d17a603ccd98fb8d2db (127.21.154.1). New cstate: current_term: 1 leader_uuid: "d46b564460354d17a603ccd98fb8d2db" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d46b564460354d17a603ccd98fb8d2db" member_type: VOTER last_known_addr { host: "127.21.154.1" port: 39483 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:28.864625 22120 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.013s	sys 0.011s
I20260812 06:18:29.015038 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushMRSOp(320268b5585c4b02a6f7fecffcfbf752): perf score=19.054940
I20260812 06:18:29.155503 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushMRSOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.140s	user 0.102s	sys 0.036s Metrics: {"bytes_written":8984540,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":728,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36697,"lbm_writes_lt_1ms":676,"mutex_wait_us":1146,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":896,"update_count":1095}
I20260812 06:18:29.156059 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling LogGCOp(320268b5585c4b02a6f7fecffcfbf752): free 20743880 bytes of WAL
I20260812 06:18:29.156266 22588 log_reader.cc:385] T 320268b5585c4b02a6f7fecffcfbf752: removed 2 log segments from log reader
I20260812 06:18:29.156328 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000001 (ops 1-6)
I20260812 06:18:29.156378 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000002 (ops 7-11)
I20260812 06:18:29.161088 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: LogGCOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.005s	user 0.002s	sys 0.000s Metrics: {}
I20260812 06:18:29.161454 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:29.175998 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3323180,"delete_count":0,"lbm_write_time_us":4794,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:18:29.176453 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling UndoDeltaBlockGCOp(320268b5585c4b02a6f7fecffcfbf752): 16411393 bytes on disk
I20260812 06:18:29.176841 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: UndoDeltaBlockGCOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"spinlock_wait_cycles":1920}
I20260812 06:18:29.177263 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:29.302469 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.125s	user 0.090s	sys 0.035s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569848,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":638,"lbm_read_time_us":8994,"lbm_reads_lt_1ms":360,"lbm_write_time_us":21531,"lbm_writes_lt_1ms":343,"mutex_wait_us":25,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":19072,"thread_start_us":333,"threads_started":5,"update_count":1500}
I20260812 06:18:29.303125 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=10.126437
I20260812 06:18:29.351166 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.048s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16411,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:29.351584 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:29.361622 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3900,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.362092 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:29.489673 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.127s	user 0.087s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":683,"lbm_read_time_us":8801,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24011,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:18:29.490314 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=10.126437
I20260812 06:18:29.543345 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.053s	user 0.010s	sys 0.035s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16231,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:29.544270 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:29.555210 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4259,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.555619 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:29.719892 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.164s	user 0.096s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1181,"lbm_read_time_us":11240,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26518,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:29.720652 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=10.126437
I20260812 06:18:29.764578 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.044s	user 0.024s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15808,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:29.765097 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:29.779930 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5913,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.780601 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:29.910738 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.130s	user 0.105s	sys 0.024s 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":573,"lbm_read_time_us":11091,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22530,"lbm_writes_lt_1ms":443,"mutex_wait_us":240,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2000}
I20260812 06:18:29.911355 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=10.126437
I20260812 06:18:29.948781 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.037s	user 0.016s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13408,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:29.949394 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:29.965973 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.016s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6754,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.966509 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:30.109124 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.142s	user 0.098s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":137,"lbm_read_time_us":9572,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27969,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:30.109812 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=10.126437
I20260812 06:18:30.160735 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.050s	user 0.035s	sys 0.013s Metrics: {"bytes_written":12430564,"delete_count":0,"lbm_write_time_us":19147,"lbm_writes_lt_1ms":306,"mutex_wait_us":173,"reinsert_count":0,"update_count":1515}
I20260812 06:18:30.161247 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:30.178817 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.017s	user 0.006s	sys 0.009s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":5696,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:18:30.179783 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:30.352788 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.173s	user 0.121s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":237,"lbm_read_time_us":12507,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29091,"lbm_writes_lt_1ms":443,"mutex_wait_us":103,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:18:30.353785 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=10.126437
I20260812 06:18:30.392490 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.039s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14900,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:30.393028 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:30.407351 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5634,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.407879 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:30.548676 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.141s	user 0.104s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":222,"lbm_read_time_us":9639,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28602,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:30.549587 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=10.126437
I20260812 06:18:30.604492 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.055s	user 0.036s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21956,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:30.605026 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:30.615530 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3991,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.616318 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushMRSOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:30.651998 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushMRSOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.035s	user 0.030s	sys 0.004s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":300,"dirs.run_wall_time_us":1207,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2305,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31,"spinlock_wait_cycles":14080}
I20260812 06:18:30.652630 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling LogGCOp(320268b5585c4b02a6f7fecffcfbf752): free 124257261 bytes of WAL
I20260812 06:18:30.652859 22588 log_reader.cc:385] T 320268b5585c4b02a6f7fecffcfbf752: removed 12 log segments from log reader
I20260812 06:18:30.652905 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000003 (ops 12-16)
I20260812 06:18:30.652935 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000004 (ops 17-21)
I20260812 06:18:30.653005 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000005 (ops 22-26)
I20260812 06:18:30.653066 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000006 (ops 27-30)
I20260812 06:18:30.653110 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000007 (ops 31-35)
I20260812 06:18:30.653177 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000008 (ops 36-40)
I20260812 06:18:30.653220 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000009 (ops 41-45)
I20260812 06:18:30.653263 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000010 (ops 46-50)
I20260812 06:18:30.653306 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000011 (ops 51-55)
I20260812 06:18:30.653352 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000012 (ops 56-60)
I20260812 06:18:30.653393 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000013 (ops 61-65)
I20260812 06:18:30.653436 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000014 (ops 66-70)
I20260812 06:18:30.683833 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: LogGCOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:18:30.684504 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:30.700093 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.015s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4830,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.700542 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling UndoDeltaBlockGCOp(320268b5585c4b02a6f7fecffcfbf752): 483 bytes on disk
I20260812 06:18:30.700908 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: UndoDeltaBlockGCOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:18:30.701311 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:30.711998 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4438,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.712422 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:30.900501 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.188s	user 0.156s	sys 0.031s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1166,"lbm_read_time_us":13110,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37172,"lbm_writes_lt_1ms":643,"mutex_wait_us":378,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20480,"thread_start_us":98,"threads_started":1,"update_count":3000}
I20260812 06:18:30.901482 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=14.095187
I20260812 06:18:30.952723 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.051s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23888,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.953230 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:30.966513 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5255,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.967133 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:31.139093 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.172s	user 0.107s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":842,"lbm_read_time_us":11336,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32922,"lbm_writes_lt_1ms":543,"mutex_wait_us":353,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":182144,"update_count":2500}
I20260812 06:18:31.139676 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=14.095187
I20260812 06:18:31.200026 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.060s	user 0.051s	sys 0.008s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":26489,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.200644 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:31.364252 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.163s	user 0.115s	sys 0.045s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":296,"lbm_read_time_us":10680,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26994,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2000}
I20260812 06:18:31.364771 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=14.095187
I20260812 06:18:31.422088 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.057s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23962,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.422610 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:31.434660 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4538,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.435258 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:31.650767 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.215s	user 0.135s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":412,"lbm_read_time_us":13042,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36197,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":31360,"update_count":2500}
I20260812 06:18:31.651511 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=14.095187
I20260812 06:18:31.704332 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.053s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":22169,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.705137 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:31.717569 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4845,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.718420 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:31.888428 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.170s	user 0.111s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":123,"lbm_read_time_us":10117,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34524,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":68480,"update_count":2500}
I20260812 06:18:31.889079 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=14.095187
I20260812 06:18:31.939597 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.050s	user 0.026s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20443,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.940204 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:31.952253 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4712,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.953001 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:32.117576 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.164s	user 0.121s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1548,"lbm_read_time_us":12506,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30118,"lbm_writes_lt_1ms":543,"mutex_wait_us":406,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20096,"update_count":2500}
I20260812 06:18:32.118479 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=14.095187
I20260812 06:18:32.170862 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.052s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19378,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:32.171402 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:32.185200 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.014s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5375,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.185642 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushMRSOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:32.215902 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushMRSOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":1050,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1416,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:32.216509 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling LogGCOp(320268b5585c4b02a6f7fecffcfbf752): free 133024390 bytes of WAL
I20260812 06:18:32.216724 22588 log_reader.cc:385] T 320268b5585c4b02a6f7fecffcfbf752: removed 13 log segments from log reader
I20260812 06:18:32.216766 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000015 (ops 71-75)
I20260812 06:18:32.216794 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000016 (ops 76-80)
I20260812 06:18:32.216856 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000017 (ops 81-85)
I20260812 06:18:32.216892 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000018 (ops 86-90)
I20260812 06:18:32.216930 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000019 (ops 91-95)
I20260812 06:18:32.216965 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000020 (ops 96-100)
I20260812 06:18:32.217006 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000021 (ops 101-105)
I20260812 06:18:32.217047 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000022 (ops 106-110)
I20260812 06:18:32.217090 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000023 (ops 111-114)
I20260812 06:18:32.217131 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000024 (ops 115-119)
I20260812 06:18:32.217170 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000025 (ops 120-124)
I20260812 06:18:32.217216 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000026 (ops 125-129)
I20260812 06:18:32.217254 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000027 (ops 130-134)
I20260812 06:18:32.245348 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: LogGCOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:32.245723 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=3.181125
I20260812 06:18:32.256834 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4448,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:32.257225 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling UndoDeltaBlockGCOp(320268b5585c4b02a6f7fecffcfbf752): 482 bytes on disk
I20260812 06:18:32.257568 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: UndoDeltaBlockGCOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:18:32.257999 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:32.270493 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3953,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:32.271215 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:32.506912 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.236s	user 0.148s	sys 0.082s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":603,"lbm_read_time_us":16022,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39244,"lbm_writes_lt_1ms":743,"mutex_wait_us":20,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:18:32.507711 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=14.095187
I20260812 06:18:32.568740 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.061s	user 0.026s	sys 0.031s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21906,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:32.569298 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:32.583225 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5564,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.583679 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:32.599128 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.015s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6447,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.599509 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:32.810140 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.210s	user 0.132s	sys 0.075s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":356,"lbm_read_time_us":14003,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32179,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17024,"update_count":3000}
I20260812 06:18:32.810788 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=16.079562
I20260812 06:18:32.880888 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.070s	user 0.034s	sys 0.020s Metrics: {"bytes_written":18461107,"delete_count":0,"lbm_write_time_us":25790,"lbm_writes_lt_1ms":453,"reinsert_count":0,"update_count":2250}
I20260812 06:18:32.881434 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=4.173312
I20260812 06:18:32.896301 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.015s	user 0.001s	sys 0.012s Metrics: {"bytes_written":6153876,"delete_count":0,"lbm_write_time_us":6323,"lbm_writes_lt_1ms":153,"reinsert_count":0,"update_count":750}
I20260812 06:18:32.897115 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:33.107432 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.210s	user 0.147s	sys 0.059s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":397,"lbm_read_time_us":15234,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34995,"lbm_writes_lt_1ms":643,"mutex_wait_us":71,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":3000}
I20260812 06:18:33.108803 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=16.079562
I20260812 06:18:33.172561 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.064s	user 0.033s	sys 0.024s Metrics: {"bytes_written":17722675,"delete_count":0,"lbm_write_time_us":26885,"lbm_writes_lt_1ms":435,"reinsert_count":0,"update_count":2160}
I20260812 06:18:33.173094 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:33.185928 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.013s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3200109,"delete_count":0,"lbm_write_time_us":3742,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:18:33.186440 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:33.200330 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5530,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:33.200886 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:33.412590 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.211s	user 0.164s	sys 0.047s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877189,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":483,"lbm_read_time_us":15502,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35277,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":53632,"update_count":3000}
I20260812 06:18:33.414960 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=14.095187
I20260812 06:18:33.463608 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.048s	user 0.019s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22686,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.464149 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:33.481909 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.018s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6826,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.482617 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:33.663672 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.181s	user 0.108s	sys 0.073s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":782,"lbm_read_time_us":12745,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30997,"lbm_writes_lt_1ms":543,"mutex_wait_us":17,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:18:33.664435 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=14.095187
I20260812 06:18:33.723538 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.059s	user 0.019s	sys 0.039s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24291,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.724188 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:33.739375 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.015s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5862,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.739874 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushMRSOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:33.769421 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushMRSOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.029s	user 0.022s	sys 0.005s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":91,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":1113,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1481,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:33.770282 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling LogGCOp(320268b5585c4b02a6f7fecffcfbf752): free 121006655 bytes of WAL
I20260812 06:18:33.770560 22588 log_reader.cc:385] T 320268b5585c4b02a6f7fecffcfbf752: removed 12 log segments from log reader
I20260812 06:18:33.770629 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000028 (ops 135-139)
I20260812 06:18:33.770686 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000029 (ops 140-144)
I20260812 06:18:33.770712 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000030 (ops 145-148)
I20260812 06:18:33.770756 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000031 (ops 149-153)
I20260812 06:18:33.770793 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000032 (ops 154-158)
I20260812 06:18:33.770831 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000033 (ops 159-163)
I20260812 06:18:33.770870 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000034 (ops 164-168)
I20260812 06:18:33.770908 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000035 (ops 169-173)
I20260812 06:18:33.770946 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000036 (ops 174-178)
I20260812 06:18:33.770984 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000037 (ops 179-183)
I20260812 06:18:33.771021 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000038 (ops 184-188)
I20260812 06:18:33.771056 22588 log.cc:1079] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: Deleting log segment in path: /tmp/dist-test-taskW4T8Le/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502938467-22120-0/minicluster-data/ts-0-root/wals/320268b5585c4b02a6f7fecffcfbf752/wal-000000039 (ops 189-193)
I20260812 06:18:33.796204 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: LogGCOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.026s	user 0.005s	sys 0.019s Metrics: {}
I20260812 06:18:33.796626 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=3.181125
I20260812 06:18:33.810315 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.014s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4662,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:33.810776 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling UndoDeltaBlockGCOp(320268b5585c4b02a6f7fecffcfbf752): 483 bytes on disk
I20260812 06:18:33.811165 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: UndoDeltaBlockGCOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:18:33.811652 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752): perf score=2.188937
I20260812 06:18:33.822832 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: FlushDeltaMemStoresOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4372,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:33.823571 22673 maintenance_manager.cc:419] P d46b564460354d17a603ccd98fb8d2db: Scheduling MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752): perf score=1.000000
I20260812 06:18:33.928174 22120 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.063s	user 1.855s	sys 0.190s
I20260812 06:18:34.016618 22120 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.088s	user 0.001s	sys 0.000s
I20260812 06:18:34.017119 22120 tablet_server.cc:179] TabletServer@127.21.154.1:0 shutting down...
I20260812 06:18:34.060070 22588 maintenance_manager.cc:643] P d46b564460354d17a603ccd98fb8d2db: MajorDeltaCompactionOp(320268b5585c4b02a6f7fecffcfbf752) complete. Timing: real 0.236s	user 0.148s	sys 0.087s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979741,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":559,"lbm_read_time_us":17036,"lbm_reads_lt_1ms":770,"lbm_write_time_us":40218,"lbm_writes_lt_1ms":743,"mutex_wait_us":75,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":20608,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:18:34.061198 22120 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:34.061559 22120 tablet_replica.cc:333] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db: stopping tablet replica
I20260812 06:18:34.061766 22120 raft_consensus.cc:2243] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:34.061990 22120 raft_consensus.cc:2272] T 320268b5585c4b02a6f7fecffcfbf752 P d46b564460354d17a603ccd98fb8d2db [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:34.079088 22120 tablet_server.cc:196] TabletServer@127.21.154.1:0 shutdown complete.
I20260812 06:18:34.119243 22120 master.cc:562] Master@127.21.154.62:44443 shutting down...
I20260812 06:18:34.124006 22120 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:34.124197 22120 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:34.124248 22120 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7b4d52ab167542de9a20a36d5885b63c: stopping tablet replica
I20260812 06:18:34.137709 22120 master.cc:584] Master@127.21.154.62:44443 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5597 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11272 ms total)

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