[==========] 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:20:10.985890 27075 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.112.254:33039
I20260812 06:20:10.986886 27075 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:20:10.987475 27075 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:10.994130 27082 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:20:10.994194 27075 server_base.cc:1061] running on GCE node
W20260812 06:20:10.994138 27081 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:20:10.994434 27086 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:20:10.994954 27075 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:10.995043 27075 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:20:10.995074 27075 hybrid_clock.cc:648] HybridClock initialized: now 1786515610995073 us; error 0 us; skew 500 ppm
I20260812 06:20:10.996774 27075 webserver.cc:533] Webserver started at http://127.26.112.254:33635/ using document root <none> and password file <none>
I20260812 06:20:10.997375 27075 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:10.997437 27075 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:10.997627 27075 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:10.999222 27075 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/master-0-root/instance:
uuid: "e9e0347ed32642e192a7e1d46e635662"
format_stamp: "Formatted at 2026-08-12 06:20:10 on dist-test-slave-ffrd"
I20260812 06:20:11.002660 27075 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:20:11.004681 27092 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:20:11.005792 27075 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:11.005924 27075 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/master-0-root
uuid: "e9e0347ed32642e192a7e1d46e635662"
format_stamp: "Formatted at 2026-08-12 06:20:10 on dist-test-slave-ffrd"
I20260812 06:20:11.006011 27075 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-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:20:11.027539 27075 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:11.028152 27075 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:20:11.028288 27075 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:11.036041 27075 rpc_server.cc:307] RPC server started. Bound to: 127.26.112.254:33039
I20260812 06:20:11.036064 27174 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.112.254:33039 every 8 connection(s)
I20260812 06:20:11.038297 27175 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:20:11.044471 27175 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662: Bootstrap starting.
I20260812 06:20:11.046887 27175 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:11.047823 27175 log.cc:826] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:11.049751 27175 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662: No bootstrap required, opened a new log
I20260812 06:20:11.052520 27175 raft_consensus.cc:359] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e9e0347ed32642e192a7e1d46e635662" member_type: VOTER }
I20260812 06:20:11.052681 27175 raft_consensus.cc:385] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:11.052752 27175 raft_consensus.cc:740] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e9e0347ed32642e192a7e1d46e635662, State: Initialized, Role: FOLLOWER
I20260812 06:20:11.053493 27175 consensus_queue.cc:260] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [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: "e9e0347ed32642e192a7e1d46e635662" member_type: VOTER }
I20260812 06:20:11.053673 27175 raft_consensus.cc:399] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:11.053761 27175 raft_consensus.cc:493] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:11.053890 27175 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:11.054693 27175 raft_consensus.cc:515] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e9e0347ed32642e192a7e1d46e635662" member_type: VOTER }
I20260812 06:20:11.055137 27175 leader_election.cc:304] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [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: e9e0347ed32642e192a7e1d46e635662; no voters: 
I20260812 06:20:11.055461 27175 leader_election.cc:290] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:11.055605 27182 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:11.055873 27182 raft_consensus.cc:697] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [term 1 LEADER]: Becoming Leader. State: Replica: e9e0347ed32642e192a7e1d46e635662, State: Running, Role: LEADER
I20260812 06:20:11.056315 27182 consensus_queue.cc:237] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [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: "e9e0347ed32642e192a7e1d46e635662" member_type: VOTER }
I20260812 06:20:11.056597 27175 sys_catalog.cc:565] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:11.058653 27185 sys_catalog.cc:455] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [sys.catalog]: SysCatalogTable state changed. Reason: New leader e9e0347ed32642e192a7e1d46e635662. Latest consensus state: current_term: 1 leader_uuid: "e9e0347ed32642e192a7e1d46e635662" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e9e0347ed32642e192a7e1d46e635662" member_type: VOTER } }
I20260812 06:20:11.058769 27185 sys_catalog.cc:458] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:11.059048 27183 sys_catalog.cc:455] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e9e0347ed32642e192a7e1d46e635662" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e9e0347ed32642e192a7e1d46e635662" member_type: VOTER } }
I20260812 06:20:11.059134 27183 sys_catalog.cc:458] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:11.059193 27075 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:11.059911 27200 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:11.062132 27200 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:11.066493 27200 catalog_manager.cc:1383] Generated new cluster ID: b0134c19ab794a3ea86dc4f6d9ed03b6
I20260812 06:20:11.066552 27200 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:11.082032 27200 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:11.082967 27200 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:11.092264 27200 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662: Generated new TSK 0
I20260812 06:20:11.092928 27200 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:11.124384 27075 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:11.127650 27213 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:20:11.127650 27210 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:20:11.127730 27211 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:20:11.128073 27075 server_base.cc:1061] running on GCE node
I20260812 06:20:11.128391 27075 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:11.128456 27075 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:20:11.128489 27075 hybrid_clock.cc:648] HybridClock initialized: now 1786515611128489 us; error 0 us; skew 500 ppm
I20260812 06:20:11.129598 27075 webserver.cc:533] Webserver started at http://127.26.112.193:41461/ using document root <none> and password file <none>
I20260812 06:20:11.129789 27075 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:11.129863 27075 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:11.129952 27075 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:11.130563 27075 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/instance:
uuid: "8fb1eec49a8e47c68593fbe3b796eb3d"
format_stamp: "Formatted at 2026-08-12 06:20:11 on dist-test-slave-ffrd"
I20260812 06:20:11.132754 27075 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:20:11.133978 27221 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:20:11.134258 27075 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:11.134369 27075 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root
uuid: "8fb1eec49a8e47c68593fbe3b796eb3d"
format_stamp: "Formatted at 2026-08-12 06:20:11 on dist-test-slave-ffrd"
I20260812 06:20:11.134452 27075 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-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:20:11.152573 27075 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:11.153195 27075 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:11.153810 27075 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:11.154835 27075 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:11.154940 27075 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:11.155067 27075 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:11.155121 27075 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:11.162752 27075 rpc_server.cc:307] RPC server started. Bound to: 127.26.112.193:43393
I20260812 06:20:11.162775 27311 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.112.193:43393 every 8 connection(s)
I20260812 06:20:11.173440 27312 heartbeater.cc:344] Connected to a master server at 127.26.112.254:33039
I20260812 06:20:11.173717 27312 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:11.174160 27312 heartbeater.cc:507] Master 127.26.112.254:33039 requested a full tablet report, sending...
I20260812 06:20:11.175642 27125 ts_manager.cc:194] Registered new tserver with Master: 8fb1eec49a8e47c68593fbe3b796eb3d (127.26.112.193:43393)
I20260812 06:20:11.175741 27075 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012241869s
I20260812 06:20:11.177218 27125 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54954
I20260812 06:20:11.188349 27125 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54966:
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:20:11.203195 27250 tablet_service.cc:1511] Processing CreateTablet for tablet 3033aa641efe48c48ade4f05bb8806dd (DEFAULT_TABLE table=heavy-update-compaction-test [id=5fff669f306b424289ca12ffd079fc80]), partition=
I20260812 06:20:11.203687 27250 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3033aa641efe48c48ade4f05bb8806dd. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:11.206135 27331 tablet_bootstrap.cc:492] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Bootstrap starting.
I20260812 06:20:11.207628 27331 tablet_bootstrap.cc:654] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:11.209115 27331 tablet_bootstrap.cc:492] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: No bootstrap required, opened a new log
I20260812 06:20:11.209220 27331 ts_tablet_manager.cc:1403] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:11.209724 27331 raft_consensus.cc:359] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8fb1eec49a8e47c68593fbe3b796eb3d" member_type: VOTER last_known_addr { host: "127.26.112.193" port: 43393 } }
I20260812 06:20:11.209900 27331 raft_consensus.cc:385] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:11.209962 27331 raft_consensus.cc:740] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8fb1eec49a8e47c68593fbe3b796eb3d, State: Initialized, Role: FOLLOWER
I20260812 06:20:11.210099 27331 consensus_queue.cc:260] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d [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: "8fb1eec49a8e47c68593fbe3b796eb3d" member_type: VOTER last_known_addr { host: "127.26.112.193" port: 43393 } }
I20260812 06:20:11.210249 27331 raft_consensus.cc:399] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:11.210304 27331 raft_consensus.cc:493] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:11.210348 27331 raft_consensus.cc:3060] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:11.211364 27331 raft_consensus.cc:515] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8fb1eec49a8e47c68593fbe3b796eb3d" member_type: VOTER last_known_addr { host: "127.26.112.193" port: 43393 } }
I20260812 06:20:11.211510 27331 leader_election.cc:304] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d [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: 8fb1eec49a8e47c68593fbe3b796eb3d; no voters: 
I20260812 06:20:11.211715 27331 leader_election.cc:290] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:11.211932 27333 raft_consensus.cc:2804] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:11.212044 27331 ts_tablet_manager.cc:1434] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:20:11.212206 27333 raft_consensus.cc:697] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d [term 1 LEADER]: Becoming Leader. State: Replica: 8fb1eec49a8e47c68593fbe3b796eb3d, State: Running, Role: LEADER
I20260812 06:20:11.212314 27312 heartbeater.cc:499] Master 127.26.112.254:33039 was elected leader, sending a full tablet report...
I20260812 06:20:11.212364 27333 consensus_queue.cc:237] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d [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: "8fb1eec49a8e47c68593fbe3b796eb3d" member_type: VOTER last_known_addr { host: "127.26.112.193" port: 43393 } }
I20260812 06:20:11.215327 27125 catalog_manager.cc:5719] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d reported cstate change: term changed from 0 to 1, leader changed from <none> to 8fb1eec49a8e47c68593fbe3b796eb3d (127.26.112.193). New cstate: current_term: 1 leader_uuid: "8fb1eec49a8e47c68593fbe3b796eb3d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8fb1eec49a8e47c68593fbe3b796eb3d" member_type: VOTER last_known_addr { host: "127.26.112.193" port: 43393 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:11.284235 27075 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.012s	sys 0.016s
I20260812 06:20:11.413909 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushMRSOp(3033aa641efe48c48ade4f05bb8806dd): perf score=15.086190
I20260812 06:20:11.578545 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushMRSOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.164s	user 0.118s	sys 0.044s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":72,"delete_count":0,"dirs.queue_time_us":88,"dirs.run_cpu_time_us":282,"dirs.run_wall_time_us":845,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41462,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1450}
I20260812 06:20:11.579881 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling LogGCOp(3033aa641efe48c48ade4f05bb8806dd): free 20743880 bytes of WAL
I20260812 06:20:11.580282 27227 log_reader.cc:385] T 3033aa641efe48c48ade4f05bb8806dd: removed 2 log segments from log reader
I20260812 06:20:11.580401 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000001 (ops 1-6)
I20260812 06:20:11.580502 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000002 (ops 7-11)
I20260812 06:20:11.586409 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: LogGCOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:20:11.586781 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:11.605888 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.019s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6095,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.606379 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:11.623477 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.017s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6775,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.623988 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling UndoDeltaBlockGCOp(3033aa641efe48c48ade4f05bb8806dd): 12719217 bytes on disk
I20260812 06:20:11.624691 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: UndoDeltaBlockGCOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:20:11.625241 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:11.796182 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.171s	user 0.122s	sys 0.045s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364566,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":733,"lbm_read_time_us":11812,"lbm_reads_lt_1ms":559,"lbm_write_time_us":31983,"lbm_writes_lt_1ms":533,"mutex_wait_us":27,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":8448,"thread_start_us":372,"threads_started":5,"update_count":2450}
I20260812 06:20:11.796793 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=10.126437
I20260812 06:20:11.830535 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.034s	user 0.020s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14074,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:11.831750 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:11.844254 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4973,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.844795 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:11.971385 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.126s	user 0.097s	sys 0.029s 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":224,"lbm_read_time_us":10168,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24090,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":30592,"update_count":2000}
I20260812 06:20:11.971985 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=10.126437
I20260812 06:20:12.020530 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.048s	user 0.032s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19269,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:12.021209 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:12.032191 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4157,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.032788 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:12.163780 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.131s	user 0.110s	sys 0.020s 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":98,"lbm_read_time_us":10109,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25707,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2000}
I20260812 06:20:12.164382 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=10.126437
I20260812 06:20:12.214268 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.050s	user 0.022s	sys 0.026s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18172,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:12.214883 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:12.228036 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.013s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4556,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.228742 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:12.380972 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.152s	user 0.107s	sys 0.044s 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":542,"lbm_read_time_us":11781,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25367,"lbm_writes_lt_1ms":443,"mutex_wait_us":299,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:20:12.381520 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=10.126437
I20260812 06:20:12.414958 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.033s	user 0.024s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13468,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:12.415408 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:12.426074 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4176,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.426517 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:12.556231 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.130s	user 0.098s	sys 0.031s 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":1239,"lbm_read_time_us":10959,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24502,"lbm_writes_lt_1ms":443,"mutex_wait_us":270,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:20:12.556767 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=10.126437
I20260812 06:20:12.605791 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.049s	user 0.017s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18595,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:12.606308 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:12.617877 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4274,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.618454 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:12.757414 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.139s	user 0.111s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":331,"lbm_read_time_us":10455,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26341,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:20:12.758018 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=10.126437
I20260812 06:20:12.807327 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.049s	user 0.025s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15721,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:12.807786 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:12.818470 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4322,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.818934 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushMRSOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:12.862982 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushMRSOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.044s	user 0.033s	sys 0.001s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1275,"drs_written":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1647,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:12.863768 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling LogGCOp(3033aa641efe48c48ade4f05bb8806dd): free 108082394 bytes of WAL
I20260812 06:20:12.864012 27227 log_reader.cc:385] T 3033aa641efe48c48ade4f05bb8806dd: removed 11 log segments from log reader
I20260812 06:20:12.864073 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000003 (ops 12-16)
I20260812 06:20:12.864128 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000004 (ops 17-20)
I20260812 06:20:12.864183 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000005 (ops 21-25)
I20260812 06:20:12.864225 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000006 (ops 26-30)
I20260812 06:20:12.864261 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000007 (ops 31-34)
I20260812 06:20:12.864297 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000008 (ops 35-39)
I20260812 06:20:12.864331 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000009 (ops 40-44)
I20260812 06:20:12.864370 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000010 (ops 45-48)
I20260812 06:20:12.864408 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000011 (ops 49-53)
I20260812 06:20:12.864444 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000012 (ops 54-58)
I20260812 06:20:12.864481 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000013 (ops 59-63)
I20260812 06:20:12.890906 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: LogGCOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:12.891392 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling UndoDeltaBlockGCOp(3033aa641efe48c48ade4f05bb8806dd): 447 bytes on disk
I20260812 06:20:12.892051 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: UndoDeltaBlockGCOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":109,"lbm_reads_lt_1ms":4}
I20260812 06:20:12.892624 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=3.181125
I20260812 06:20:12.915642 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.023s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7234,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:12.916105 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:12.926386 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3945,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:12.926838 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:13.128451 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.201s	user 0.116s	sys 0.083s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2550,"lbm_read_time_us":14773,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32708,"lbm_writes_lt_1ms":643,"mutex_wait_us":1809,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8192,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:20:13.129150 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=14.095187
I20260812 06:20:13.195712 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.066s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24010,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:13.196220 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:13.208074 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4727,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.208848 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:13.390190 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.181s	user 0.116s	sys 0.057s 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":356,"lbm_read_time_us":13944,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31524,"lbm_writes_lt_1ms":543,"mutex_wait_us":77,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:13.390781 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=14.095187
I20260812 06:20:13.454735 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.064s	user 0.021s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18697,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:13.455258 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:13.466293 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4325,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.466784 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:13.651970 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.185s	user 0.128s	sys 0.056s 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":402,"lbm_read_time_us":14420,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31393,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:13.652655 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=11.118625
I20260812 06:20:13.688285 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.035s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15611,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:13.688980 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:13.709690 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.021s	user 0.007s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6033,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:13.710330 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:13.864492 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.154s	user 0.097s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":794,"lbm_read_time_us":10919,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24732,"lbm_writes_lt_1ms":443,"mutex_wait_us":343,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:13.865163 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=10.126437
I20260812 06:20:13.909629 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.044s	user 0.022s	sys 0.021s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21638,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.910214 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:13.933588 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.023s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5372,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.934052 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:13.946664 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5189,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.947378 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:14.099051 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.151s	user 0.107s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":209,"lbm_read_time_us":12930,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30252,"lbm_writes_lt_1ms":543,"mutex_wait_us":102,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:20:14.099828 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=10.126437
I20260812 06:20:14.141985 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.042s	user 0.029s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17893,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.142470 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:14.165505 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.023s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6098,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":500}
I20260812 06:20:14.166046 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:14.177603 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4440,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.178421 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:14.341107 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.162s	user 0.104s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774806,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":750,"lbm_read_time_us":10938,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31184,"lbm_writes_lt_1ms":543,"mutex_wait_us":302,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:14.342321 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=14.095187
I20260812 06:20:14.394820 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.052s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24748,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:14.395466 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:14.411088 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5416,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.411605 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushMRSOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:14.464000 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushMRSOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.052s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":99,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":1195,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2685,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:14.464749 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling LogGCOp(3033aa641efe48c48ade4f05bb8806dd): free 132571312 bytes of WAL
I20260812 06:20:14.465045 27227 log_reader.cc:385] T 3033aa641efe48c48ade4f05bb8806dd: removed 13 log segments from log reader
I20260812 06:20:14.465090 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000014 (ops 64-68)
I20260812 06:20:14.465119 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000015 (ops 69-73)
I20260812 06:20:14.465178 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000016 (ops 74-78)
I20260812 06:20:14.465222 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000017 (ops 79-83)
I20260812 06:20:14.465262 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000018 (ops 84-88)
I20260812 06:20:14.465302 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000019 (ops 89-93)
I20260812 06:20:14.465341 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000020 (ops 94-98)
I20260812 06:20:14.465381 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000021 (ops 99-102)
I20260812 06:20:14.465420 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000022 (ops 103-107)
I20260812 06:20:14.465459 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000023 (ops 108-112)
I20260812 06:20:14.465498 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000024 (ops 113-116)
I20260812 06:20:14.465538 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000025 (ops 117-121)
I20260812 06:20:14.465576 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000026 (ops 122-126)
I20260812 06:20:14.497344 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: LogGCOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.032s	user 0.005s	sys 0.027s Metrics: {}
I20260812 06:20:14.497879 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=7.149875
I20260812 06:20:14.518529 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.020s	user 0.009s	sys 0.009s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9048,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:14.519222 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling LogGCOp(3033aa641efe48c48ade4f05bb8806dd): free 8767130 bytes of WAL
I20260812 06:20:14.519541 27227 log_reader.cc:385] T 3033aa641efe48c48ade4f05bb8806dd: removed 1 log segments from log reader
I20260812 06:20:14.519611 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000027 (ops 127-131)
I20260812 06:20:14.522472 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: LogGCOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:14.522821 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling UndoDeltaBlockGCOp(3033aa641efe48c48ade4f05bb8806dd): 493 bytes on disk
I20260812 06:20:14.523283 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: UndoDeltaBlockGCOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:20:14.523813 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:14.539148 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.015s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5527,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:14.539661 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:14.759083 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.219s	user 0.151s	sys 0.064s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082155,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":534,"lbm_read_time_us":16563,"lbm_reads_lt_1ms":866,"lbm_write_time_us":45561,"lbm_writes_lt_1ms":843,"mutex_wait_us":69,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":101,"threads_started":1,"update_count":4000}
I20260812 06:20:14.759647 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=18.063937
I20260812 06:20:14.850761 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.091s	user 0.030s	sys 0.059s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":34641,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:20:14.851387 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:14.876374 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.025s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6962,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.876832 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:14.887796 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4356,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.888341 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:15.142891 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.254s	user 0.149s	sys 0.095s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979633,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":421,"lbm_read_time_us":18474,"lbm_reads_lt_1ms":773,"lbm_write_time_us":40172,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":3500}
I20260812 06:20:15.143505 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=18.063937
I20260812 06:20:15.222565 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.079s	user 0.042s	sys 0.028s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":33057,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:15.223073 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:15.235093 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4650,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.235882 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:15.441665 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.206s	user 0.114s	sys 0.091s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":332,"lbm_read_time_us":16611,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33533,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":3000}
I20260812 06:20:15.442693 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=15.087375
I20260812 06:20:15.495471 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.053s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":24292,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:15.496089 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:15.506951 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3965,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:15.507429 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:15.695472 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.188s	user 0.133s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774677,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":132,"lbm_read_time_us":14100,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32990,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:15.696167 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=14.095187
I20260812 06:20:15.758097 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.061s	user 0.038s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24159,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.758690 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:15.769425 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4279,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.769856 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:15.951939 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.182s	user 0.118s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":367,"lbm_read_time_us":13498,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31286,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:15.952494 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=14.095187
I20260812 06:20:16.019935 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.067s	user 0.022s	sys 0.042s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":28959,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.021021 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:16.041545 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.020s	user 0.015s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7647,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.042295 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushMRSOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:16.075685 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushMRSOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.033s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":94,"dirs.run_cpu_time_us":293,"dirs.run_wall_time_us":1747,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1876,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:16.076691 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling LogGCOp(3033aa641efe48c48ade4f05bb8806dd): free 120553636 bytes of WAL
I20260812 06:20:16.076968 27227 log_reader.cc:385] T 3033aa641efe48c48ade4f05bb8806dd: removed 12 log segments from log reader
I20260812 06:20:16.077033 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000028 (ops 132-136)
I20260812 06:20:16.077075 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000029 (ops 137-141)
I20260812 06:20:16.077098 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000030 (ops 142-146)
I20260812 06:20:16.077121 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000031 (ops 147-150)
I20260812 06:20:16.077203 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000032 (ops 151-155)
I20260812 06:20:16.077243 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000033 (ops 156-160)
I20260812 06:20:16.077270 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000034 (ops 161-164)
I20260812 06:20:16.077292 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000035 (ops 165-169)
I20260812 06:20:16.077323 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000036 (ops 170-174)
I20260812 06:20:16.077346 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000037 (ops 175-179)
I20260812 06:20:16.077380 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000038 (ops 180-184)
I20260812 06:20:16.077414 27227 log.cc:1079] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/3033aa641efe48c48ade4f05bb8806dd/wal-000000039 (ops 185-189)
I20260812 06:20:16.111204 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: LogGCOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.034s	user 0.001s	sys 0.031s Metrics: {}
I20260812 06:20:16.111680 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:16.140550 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.029s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5479,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.141119 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling UndoDeltaBlockGCOp(3033aa641efe48c48ade4f05bb8806dd): 472 bytes on disk
I20260812 06:20:16.141522 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: UndoDeltaBlockGCOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:20:16.142028 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=2.188937
I20260812 06:20:16.154079 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4419,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.154582 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:16.335325 27075 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.051s	user 1.888s	sys 0.144s
I20260812 06:20:16.377223 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.222s	user 0.138s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979752,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":15865,"lbm_reads_lt_1ms":770,"lbm_write_time_us":39985,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":3500}
I20260812 06:20:16.377914 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd): perf score=14.095187
I20260812 06:20:16.412634 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: FlushDeltaMemStoresOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.035s	user 0.013s	sys 0.021s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17256,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.413282 27314 maintenance_manager.cc:419] P 8fb1eec49a8e47c68593fbe3b796eb3d: Scheduling MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd): perf score=1.000000
I20260812 06:20:16.449999 27075 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.114s	user 0.003s	sys 0.000s
I20260812 06:20:16.450687 27075 tablet_server.cc:179] TabletServer@127.26.112.193:0 shutting down...
I20260812 06:20:16.544704 27227 maintenance_manager.cc:643] P 8fb1eec49a8e47c68593fbe3b796eb3d: MajorDeltaCompactionOp(3033aa641efe48c48ade4f05bb8806dd) complete. Timing: real 0.131s	user 0.098s	sys 0.033s 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":419,"lbm_read_time_us":13690,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23509,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":2000}
I20260812 06:20:16.545974 27075 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:16.546386 27075 tablet_replica.cc:333] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d: stopping tablet replica
I20260812 06:20:16.546624 27075 raft_consensus.cc:2243] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:16.546859 27075 raft_consensus.cc:2272] T 3033aa641efe48c48ade4f05bb8806dd P 8fb1eec49a8e47c68593fbe3b796eb3d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:16.562348 27075 tablet_server.cc:196] TabletServer@127.26.112.193:0 shutdown complete.
I20260812 06:20:16.583981 27075 master.cc:562] Master@127.26.112.254:33039 shutting down...
I20260812 06:20:16.587874 27075 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:16.588076 27075 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:16.588179 27075 tablet_replica.cc:333] T 00000000000000000000000000000000 P e9e0347ed32642e192a7e1d46e635662: stopping tablet replica
I20260812 06:20:16.600728 27075 master.cc:584] Master@127.26.112.254:33039 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5708 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:16.694231 27075 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.112.254:42889
I20260812 06:20:16.694628 27075 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:16.696547 27369 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:20:16.696614 27075 server_base.cc:1061] running on GCE node
W20260812 06:20:16.696736 27371 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:20:16.696714 27367 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:20:16.697117 27075 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:16.697162 27075 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:20:16.697178 27075 hybrid_clock.cc:648] HybridClock initialized: now 1786515616697178 us; error 0 us; skew 500 ppm
I20260812 06:20:16.697999 27075 webserver.cc:533] Webserver started at http://127.26.112.254:43789/ using document root <none> and password file <none>
I20260812 06:20:16.698128 27075 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:16.698167 27075 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:16.698218 27075 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:16.698550 27075 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/master-0-root/instance:
uuid: "f5e849bde6fa4a498aea5cb8159b1aa8"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-ffrd"
I20260812 06:20:16.699971 27075 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:16.700817 27379 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:20:16.701122 27075 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:16.701215 27075 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/master-0-root
uuid: "f5e849bde6fa4a498aea5cb8159b1aa8"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-ffrd"
I20260812 06:20:16.701295 27075 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-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:20:16.706936 27075 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:16.707263 27075 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:16.711601 27075 rpc_server.cc:307] RPC server started. Bound to: 127.26.112.254:42889
I20260812 06:20:16.720469 27471 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.112.254:42889 every 8 connection(s)
I20260812 06:20:16.721498 27472 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:20:16.732496 27472 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8: Bootstrap starting.
I20260812 06:20:16.733574 27472 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:16.734714 27472 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8: No bootstrap required, opened a new log
I20260812 06:20:16.735139 27472 raft_consensus.cc:359] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f5e849bde6fa4a498aea5cb8159b1aa8" member_type: VOTER }
I20260812 06:20:16.735256 27472 raft_consensus.cc:385] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:16.735343 27472 raft_consensus.cc:740] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f5e849bde6fa4a498aea5cb8159b1aa8, State: Initialized, Role: FOLLOWER
I20260812 06:20:16.735512 27472 consensus_queue.cc:260] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [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: "f5e849bde6fa4a498aea5cb8159b1aa8" member_type: VOTER }
I20260812 06:20:16.735625 27472 raft_consensus.cc:399] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:16.735675 27472 raft_consensus.cc:493] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:16.735734 27472 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:16.736433 27472 raft_consensus.cc:515] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f5e849bde6fa4a498aea5cb8159b1aa8" member_type: VOTER }
I20260812 06:20:16.736588 27472 leader_election.cc:304] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [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: f5e849bde6fa4a498aea5cb8159b1aa8; no voters: 
I20260812 06:20:16.736799 27472 leader_election.cc:290] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:16.736933 27475 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:16.737248 27475 raft_consensus.cc:697] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [term 1 LEADER]: Becoming Leader. State: Replica: f5e849bde6fa4a498aea5cb8159b1aa8, State: Running, Role: LEADER
I20260812 06:20:16.737308 27472 sys_catalog.cc:565] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:16.737425 27475 consensus_queue.cc:237] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [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: "f5e849bde6fa4a498aea5cb8159b1aa8" member_type: VOTER }
I20260812 06:20:16.737876 27476 sys_catalog.cc:455] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f5e849bde6fa4a498aea5cb8159b1aa8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f5e849bde6fa4a498aea5cb8159b1aa8" member_type: VOTER } }
I20260812 06:20:16.737988 27476 sys_catalog.cc:458] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:16.737891 27477 sys_catalog.cc:455] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [sys.catalog]: SysCatalogTable state changed. Reason: New leader f5e849bde6fa4a498aea5cb8159b1aa8. Latest consensus state: current_term: 1 leader_uuid: "f5e849bde6fa4a498aea5cb8159b1aa8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f5e849bde6fa4a498aea5cb8159b1aa8" member_type: VOTER } }
I20260812 06:20:16.738044 27477 sys_catalog.cc:458] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:16.738269 27483 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:16.739101 27483 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:16.739326 27075 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:16.741029 27483 catalog_manager.cc:1383] Generated new cluster ID: 271a011057f34e6ca4a5eadfcbb77cfb
I20260812 06:20:16.741086 27483 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:16.748986 27483 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:16.749543 27483 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:16.757781 27483 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8: Generated new TSK 0
I20260812 06:20:16.757966 27483 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:16.771765 27075 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:16.773754 27506 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:20:16.773787 27504 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:20:16.773810 27508 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:20:16.774057 27075 server_base.cc:1061] running on GCE node
I20260812 06:20:16.774245 27075 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:16.774300 27075 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:20:16.774335 27075 hybrid_clock.cc:648] HybridClock initialized: now 1786515616774335 us; error 0 us; skew 500 ppm
I20260812 06:20:16.775261 27075 webserver.cc:533] Webserver started at http://127.26.112.193:38037/ using document root <none> and password file <none>
I20260812 06:20:16.775447 27075 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:16.775508 27075 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:16.775610 27075 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:16.776017 27075 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/instance:
uuid: "7e1dbb6c5aa24b5ab7c3afebf84de363"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-ffrd"
I20260812 06:20:16.777616 27075 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:16.778645 27517 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:20:16.778909 27075 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:16.778980 27075 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root
uuid: "7e1dbb6c5aa24b5ab7c3afebf84de363"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-ffrd"
I20260812 06:20:16.779026 27075 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-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:20:16.797683 27075 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:16.798019 27075 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:16.798275 27075 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:16.798761 27075 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:16.798800 27075 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:16.798833 27075 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:16.798890 27075 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:16.803264 27075 rpc_server.cc:307] RPC server started. Bound to: 127.26.112.193:43957
I20260812 06:20:16.803308 27624 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.112.193:43957 every 8 connection(s)
I20260812 06:20:16.811189 27626 heartbeater.cc:344] Connected to a master server at 127.26.112.254:42889
I20260812 06:20:16.811285 27626 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:16.811517 27626 heartbeater.cc:507] Master 127.26.112.254:42889 requested a full tablet report, sending...
I20260812 06:20:16.812179 27404 ts_manager.cc:194] Registered new tserver with Master: 7e1dbb6c5aa24b5ab7c3afebf84de363 (127.26.112.193:43957)
I20260812 06:20:16.812685 27075 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008976372s
I20260812 06:20:16.812925 27404 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50762
I20260812 06:20:16.820371 27404 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50772:
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:20:16.829108 27567 tablet_service.cc:1511] Processing CreateTablet for tablet dc88d464fa7a48b78ee7a97a7bf6b0f5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=fca9a33240d3435ab7ed6ad296137a25]), partition=
I20260812 06:20:16.829391 27567 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet dc88d464fa7a48b78ee7a97a7bf6b0f5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:16.831759 27641 tablet_bootstrap.cc:492] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Bootstrap starting.
I20260812 06:20:16.832605 27641 tablet_bootstrap.cc:654] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:16.833653 27641 tablet_bootstrap.cc:492] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: No bootstrap required, opened a new log
I20260812 06:20:16.833724 27641 ts_tablet_manager.cc:1403] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:16.834158 27641 raft_consensus.cc:359] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7e1dbb6c5aa24b5ab7c3afebf84de363" member_type: VOTER last_known_addr { host: "127.26.112.193" port: 43957 } }
I20260812 06:20:16.834252 27641 raft_consensus.cc:385] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:16.834275 27641 raft_consensus.cc:740] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7e1dbb6c5aa24b5ab7c3afebf84de363, State: Initialized, Role: FOLLOWER
I20260812 06:20:16.834414 27641 consensus_queue.cc:260] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363 [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: "7e1dbb6c5aa24b5ab7c3afebf84de363" member_type: VOTER last_known_addr { host: "127.26.112.193" port: 43957 } }
I20260812 06:20:16.834522 27641 raft_consensus.cc:399] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:16.834580 27641 raft_consensus.cc:493] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:16.834642 27641 raft_consensus.cc:3060] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:16.835449 27641 raft_consensus.cc:515] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7e1dbb6c5aa24b5ab7c3afebf84de363" member_type: VOTER last_known_addr { host: "127.26.112.193" port: 43957 } }
I20260812 06:20:16.835597 27641 leader_election.cc:304] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363 [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: 7e1dbb6c5aa24b5ab7c3afebf84de363; no voters: 
I20260812 06:20:16.835804 27641 leader_election.cc:290] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:16.836009 27645 raft_consensus.cc:2804] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:16.836205 27626 heartbeater.cc:499] Master 127.26.112.254:42889 was elected leader, sending a full tablet report...
I20260812 06:20:16.836226 27641 ts_tablet_manager.cc:1434] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:16.836498 27645 raft_consensus.cc:697] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363 [term 1 LEADER]: Becoming Leader. State: Replica: 7e1dbb6c5aa24b5ab7c3afebf84de363, State: Running, Role: LEADER
I20260812 06:20:16.836640 27645 consensus_queue.cc:237] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363 [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: "7e1dbb6c5aa24b5ab7c3afebf84de363" member_type: VOTER last_known_addr { host: "127.26.112.193" port: 43957 } }
I20260812 06:20:16.838001 27404 catalog_manager.cc:5719] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363 reported cstate change: term changed from 0 to 1, leader changed from <none> to 7e1dbb6c5aa24b5ab7c3afebf84de363 (127.26.112.193). New cstate: current_term: 1 leader_uuid: "7e1dbb6c5aa24b5ab7c3afebf84de363" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7e1dbb6c5aa24b5ab7c3afebf84de363" member_type: VOTER last_known_addr { host: "127.26.112.193" port: 43957 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:16.900797 27075 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.019s	sys 0.004s
I20260812 06:20:17.054482 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushMRSOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=19.054940
I20260812 06:20:17.229573 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushMRSOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.175s	user 0.124s	sys 0.049s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":797,"drs_written":1,"lbm_read_time_us":107,"lbm_reads_lt_1ms":4,"lbm_write_time_us":48959,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":756,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":1792,"update_count":1500}
I20260812 06:20:17.230233 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling LogGCOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): free 20290830 bytes of WAL
I20260812 06:20:17.230468 27526 log_reader.cc:385] T dc88d464fa7a48b78ee7a97a7bf6b0f5: removed 2 log segments from log reader
I20260812 06:20:17.230535 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000001 (ops 1-6)
I20260812 06:20:17.230593 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000002 (ops 7-10)
I20260812 06:20:17.235067 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: LogGCOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:17.235450 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:17.253124 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5741,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.253613 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:17.431830 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.178s	user 0.097s	sys 0.070s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":648,"lbm_read_time_us":11091,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25827,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":329,"threads_started":5,"update_count":2000}
I20260812 06:20:17.432401 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling UndoDeltaBlockGCOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): 16411393 bytes on disk
I20260812 06:20:17.433529 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: UndoDeltaBlockGCOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":105,"lbm_reads_lt_1ms":4}
I20260812 06:20:17.433975 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=14.095187
I20260812 06:20:17.486821 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.052s	user 0.027s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22278,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.487397 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:17.502873 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5780,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.503573 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:17.661340 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.158s	user 0.130s	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":775,"lbm_read_time_us":13023,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30518,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:20:17.662086 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=10.126437
I20260812 06:20:17.695485 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.033s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14747,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.695935 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:17.711897 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5774,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.712486 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:17.850394 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.138s	user 0.109s	sys 0.027s 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":213,"lbm_read_time_us":10736,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27453,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2000}
I20260812 06:20:17.851189 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=11.118625
I20260812 06:20:17.908252 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.057s	user 0.032s	sys 0.022s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18776,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:17.909075 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:17.920385 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4567,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:17.920835 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:18.091848 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.171s	user 0.101s	sys 0.069s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":567,"lbm_read_time_us":12192,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28505,"lbm_writes_lt_1ms":443,"mutex_wait_us":309,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.092569 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=10.126437
I20260812 06:20:18.133157 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.040s	user 0.040s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17985,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.133762 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:18.144841 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4338,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.145570 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:18.278666 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.133s	user 0.103s	sys 0.028s 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":2048,"lbm_read_time_us":10995,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24177,"lbm_writes_lt_1ms":443,"mutex_wait_us":868,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:20:18.279799 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=10.126437
I20260812 06:20:18.322885 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.042s	user 0.020s	sys 0.020s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19057,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.323475 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:18.336015 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5046,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.336513 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:18.466969 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.130s	user 0.100s	sys 0.030s 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":340,"lbm_read_time_us":10366,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25464,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2000}
I20260812 06:20:18.467608 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=10.126437
I20260812 06:20:18.508899 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.041s	user 0.015s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15777,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.509387 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:18.520042 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4394,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.520500 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushMRSOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:18.551123 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushMRSOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.030s	user 0.026s	sys 0.003s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":96,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":1270,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2052,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:18.551811 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling LogGCOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): free 116849457 bytes of WAL
I20260812 06:20:18.552073 27526 log_reader.cc:385] T dc88d464fa7a48b78ee7a97a7bf6b0f5: removed 12 log segments from log reader
I20260812 06:20:18.552139 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000003 (ops 11-15)
I20260812 06:20:18.552192 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000004 (ops 16-20)
I20260812 06:20:18.552250 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000005 (ops 21-25)
I20260812 06:20:18.552291 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000006 (ops 26-30)
I20260812 06:20:18.552330 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000007 (ops 31-34)
I20260812 06:20:18.552367 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000008 (ops 35-39)
I20260812 06:20:18.552410 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000009 (ops 40-44)
I20260812 06:20:18.552446 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000010 (ops 45-48)
I20260812 06:20:18.552484 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000011 (ops 49-53)
I20260812 06:20:18.552521 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000012 (ops 54-58)
I20260812 06:20:18.552556 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000013 (ops 59-62)
I20260812 06:20:18.552594 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000014 (ops 63-67)
I20260812 06:20:18.580729 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: LogGCOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:18.581305 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=3.181125
I20260812 06:20:18.599560 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.018s	user 0.014s	sys 0.002s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":7196,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:18.600075 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:18.610834 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4207,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.611514 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:18.793867 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.182s	user 0.161s	sys 0.019s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":303,"lbm_read_time_us":14899,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36029,"lbm_writes_lt_1ms":643,"mutex_wait_us":48,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9344,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:20:18.794622 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=14.095187
I20260812 06:20:18.851963 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.057s	user 0.020s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23024,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.852468 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:18.864038 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4239,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.864499 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:19.025512 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.161s	user 0.116s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":975,"lbm_read_time_us":10378,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30931,"lbm_writes_lt_1ms":543,"mutex_wait_us":371,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18304,"update_count":2500}
I20260812 06:20:19.026237 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling UndoDeltaBlockGCOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): 463 bytes on disk
I20260812 06:20:19.026680 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: UndoDeltaBlockGCOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:20:19.027158 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=14.095187
I20260812 06:20:19.072433 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.045s	user 0.029s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21237,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.072909 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:19.237244 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.164s	user 0.087s	sys 0.066s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":993,"lbm_read_time_us":13119,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25057,"lbm_writes_lt_1ms":443,"mutex_wait_us":406,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":2000}
I20260812 06:20:19.237866 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=14.095187
I20260812 06:20:19.290949 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.053s	user 0.027s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21532,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.291531 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:19.303730 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4573,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.304252 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:19.502210 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.198s	user 0.124s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":740,"lbm_read_time_us":13003,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30649,"lbm_writes_lt_1ms":543,"mutex_wait_us":385,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":31104,"update_count":2500}
I20260812 06:20:19.502893 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=14.095187
I20260812 06:20:19.552424 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.049s	user 0.022s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22047,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.552932 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:19.565986 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5087,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.566478 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:19.741132 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.174s	user 0.119s	sys 0.043s 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":384,"lbm_read_time_us":11637,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34681,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2500}
I20260812 06:20:19.741869 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=14.095187
I20260812 06:20:19.793668 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.052s	user 0.039s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23507,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.794277 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:19.806896 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4986,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.807515 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:19.957309 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.150s	user 0.098s	sys 0.045s 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":365,"lbm_read_time_us":11391,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29684,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":55424,"update_count":2500}
I20260812 06:20:19.958017 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=14.095187
I20260812 06:20:20.012837 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.055s	user 0.039s	sys 0.004s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":21036,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.013397 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:20.025770 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.012s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4516,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.026315 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushMRSOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:20.057636 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushMRSOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.031s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1137,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1562,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:20.058281 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling LogGCOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): free 129320562 bytes of WAL
I20260812 06:20:20.058531 27526 log_reader.cc:385] T dc88d464fa7a48b78ee7a97a7bf6b0f5: removed 13 log segments from log reader
I20260812 06:20:20.058575 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000015 (ops 68-72)
I20260812 06:20:20.058604 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000016 (ops 73-77)
I20260812 06:20:20.058660 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000017 (ops 78-82)
I20260812 06:20:20.058702 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000018 (ops 83-86)
I20260812 06:20:20.058753 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000019 (ops 87-91)
I20260812 06:20:20.058794 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000020 (ops 92-96)
I20260812 06:20:20.058833 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000021 (ops 97-100)
I20260812 06:20:20.058879 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000022 (ops 101-105)
I20260812 06:20:20.058921 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000023 (ops 106-110)
I20260812 06:20:20.058965 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000024 (ops 111-115)
I20260812 06:20:20.059005 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000025 (ops 116-120)
I20260812 06:20:20.059046 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000026 (ops 121-125)
I20260812 06:20:20.059085 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000027 (ops 126-130)
I20260812 06:20:20.091945 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: LogGCOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.033s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:20:20.092623 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling UndoDeltaBlockGCOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): 482 bytes on disk
I20260812 06:20:20.093291 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: UndoDeltaBlockGCOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:20:20.094103 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=4.173312
I20260812 06:20:20.114838 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.021s	user 0.010s	sys 0.009s Metrics: {"bytes_written":6400017,"delete_count":0,"lbm_write_time_us":8894,"lbm_writes_lt_1ms":159,"reinsert_count":0,"update_count":780}
I20260812 06:20:20.115634 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:20.123294 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.007s	user 0.000s	sys 0.006s Metrics: {"bytes_written":1805252,"delete_count":0,"lbm_write_time_us":2442,"lbm_writes_lt_1ms":47,"reinsert_count":0,"update_count":220}
I20260812 06:20:20.123983 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:20.358265 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.234s	user 0.146s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979694,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":850,"lbm_read_time_us":15486,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39173,"lbm_writes_lt_1ms":743,"mutex_wait_us":390,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5888,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:20:20.361999 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=18.063937
I20260812 06:20:20.439644 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.077s	user 0.036s	sys 0.040s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":32385,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:20:20.440110 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=3.181125
I20260812 06:20:20.453691 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4573,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:20.454102 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:20.463871 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3777,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:20.464272 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:20.687641 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.223s	user 0.155s	sys 0.067s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979623,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1064,"lbm_read_time_us":17531,"lbm_reads_lt_1ms":773,"lbm_write_time_us":41941,"lbm_writes_lt_1ms":743,"mutex_wait_us":329,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":3500}
I20260812 06:20:20.688274 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=18.063937
I20260812 06:20:20.749317 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.061s	user 0.044s	sys 0.012s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26206,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:20.749779 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:20.762172 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.762825 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:20.947212 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.184s	user 0.158s	sys 0.025s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":626,"lbm_read_time_us":13837,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37512,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":3000}
I20260812 06:20:20.948060 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=14.095187
I20260812 06:20:21.010455 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.062s	user 0.033s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27891,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.011106 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:21.037631 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.026s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5884,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.038168 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:21.049142 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4157,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.049911 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:21.225232 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.175s	user 0.125s	sys 0.050s 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":224,"lbm_read_time_us":14307,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35607,"lbm_writes_lt_1ms":643,"mutex_wait_us":65,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":3000}
I20260812 06:20:21.225871 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=14.095187
I20260812 06:20:21.269977 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.044s	user 0.026s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19987,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.270576 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:21.288069 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.017s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6522,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.288573 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:21.456177 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.167s	user 0.137s	sys 0.019s 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":403,"lbm_read_time_us":10251,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31381,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":33664,"update_count":2500}
I20260812 06:20:21.456969 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=14.095187
I20260812 06:20:21.522116 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.065s	user 0.041s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24800,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.522603 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=2.188937
I20260812 06:20:21.533651 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4004,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.534226 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushMRSOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:21.564210 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushMRSOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.030s	user 0.023s	sys 0.005s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":88,"dirs.run_cpu_time_us":318,"dirs.run_wall_time_us":1259,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1686,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:21.564985 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling LogGCOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): free 124257457 bytes of WAL
I20260812 06:20:21.565217 27526 log_reader.cc:385] T dc88d464fa7a48b78ee7a97a7bf6b0f5: removed 12 log segments from log reader
I20260812 06:20:21.565259 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000028 (ops 131-135)
I20260812 06:20:21.565289 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000029 (ops 136-140)
I20260812 06:20:21.565349 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000030 (ops 141-145)
I20260812 06:20:21.565392 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000031 (ops 146-150)
I20260812 06:20:21.565420 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000032 (ops 151-155)
I20260812 06:20:21.565478 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000033 (ops 156-160)
I20260812 06:20:21.565521 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000034 (ops 161-164)
I20260812 06:20:21.565560 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000035 (ops 165-169)
I20260812 06:20:21.565599 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000036 (ops 170-174)
I20260812 06:20:21.565639 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000037 (ops 175-179)
I20260812 06:20:21.565676 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000038 (ops 180-184)
I20260812 06:20:21.565714 27526 log.cc:1079] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: Deleting log segment in path: /tmp/dist-test-taskM6zxL8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515610975146-27075-0/minicluster-data/ts-0-root/wals/dc88d464fa7a48b78ee7a97a7bf6b0f5/wal-000000039 (ops 185-189)
I20260812 06:20:21.595443 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: LogGCOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.030s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:21.595901 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=4.173312
I20260812 06:20:21.611450 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":5374417,"delete_count":0,"lbm_write_time_us":6510,"lbm_writes_lt_1ms":134,"reinsert_count":0,"update_count":655}
I20260812 06:20:21.611922 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.196750
I20260812 06:20:21.622326 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3841,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:20:21.622805 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=1.000000
I20260812 06:20:21.754163 27075 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.853s	user 1.791s	sys 0.104s
I20260812 06:20:21.830708 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: MajorDeltaCompactionOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.208s	user 0.129s	sys 0.078s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979725,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":162,"lbm_read_time_us":18227,"lbm_reads_lt_1ms":770,"lbm_write_time_us":36866,"lbm_writes_lt_1ms":743,"mutex_wait_us":29,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13824,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:20:21.831811 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling UndoDeltaBlockGCOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): 483 bytes on disk
I20260812 06:20:21.832984 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: UndoDeltaBlockGCOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":115,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.833626 27627 maintenance_manager.cc:419] P 7e1dbb6c5aa24b5ab7c3afebf84de363: Scheduling FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5): perf score=10.126437
I20260812 06:20:21.841671 27075 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.087s	user 0.004s	sys 0.000s
I20260812 06:20:21.842258 27075 tablet_server.cc:179] TabletServer@127.26.112.193:0 shutting down...
I20260812 06:20:21.868640 27526 maintenance_manager.cc:643] P 7e1dbb6c5aa24b5ab7c3afebf84de363: FlushDeltaMemStoresOp(dc88d464fa7a48b78ee7a97a7bf6b0f5) complete. Timing: real 0.035s	user 0.012s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15855,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.869303 27075 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:21.869535 27075 tablet_replica.cc:333] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363: stopping tablet replica
I20260812 06:20:21.869710 27075 raft_consensus.cc:2243] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:21.869911 27075 raft_consensus.cc:2272] T dc88d464fa7a48b78ee7a97a7bf6b0f5 P 7e1dbb6c5aa24b5ab7c3afebf84de363 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:21.874083 27075 tablet_server.cc:196] TabletServer@127.26.112.193:0 shutdown complete.
I20260812 06:20:21.888783 27075 master.cc:562] Master@127.26.112.254:42889 shutting down...
I20260812 06:20:21.892427 27075 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:21.892606 27075 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:21.892657 27075 tablet_replica.cc:333] T 00000000000000000000000000000000 P f5e849bde6fa4a498aea5cb8159b1aa8: stopping tablet replica
I20260812 06:20:21.905539 27075 master.cc:584] Master@127.26.112.254:42889 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5304 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11014 ms total)

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