[==========] 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:16:56.755486  8268 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.19.62:35149
I20260812 06:16:56.756472  8268 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:16:56.757068  8268 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:56.764015  8274 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:16:56.764114  8268 server_base.cc:1061] running on GCE node
W20260812 06:16:56.764026  8276 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:16:56.764313  8273 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:16:56.764923  8268 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:56.765071  8268 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:16:56.765123  8268 hybrid_clock.cc:648] HybridClock initialized: now 1786515416765121 us; error 0 us; skew 500 ppm
I20260812 06:16:56.766990  8268 webserver.cc:533] Webserver started at http://127.8.19.62:41731/ using document root <none> and password file <none>
I20260812 06:16:56.767556  8268 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:56.767647  8268 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:56.767904  8268 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:56.769588  8268 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/master-0-root/instance:
uuid: "dc6a3be04fce45dfb87b41c204885231"
format_stamp: "Formatted at 2026-08-12 06:16:56 on dist-test-slave-69rg"
I20260812 06:16:56.773134  8268 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.002s
I20260812 06:16:56.775267  8285 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:16:56.776232  8268 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:16:56.776386  8268 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/master-0-root
uuid: "dc6a3be04fce45dfb87b41c204885231"
format_stamp: "Formatted at 2026-08-12 06:16:56 on dist-test-slave-69rg"
I20260812 06:16:56.776491  8268 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-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:16:56.797187  8268 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:56.797900  8268 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:16:56.798105  8268 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:56.807796  8347 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.19.62:35149 every 8 connection(s)
I20260812 06:16:56.807806  8268 rpc_server.cc:307] RPC server started. Bound to: 127.8.19.62:35149
I20260812 06:16:56.810326  8349 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:16:56.816304  8349 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231: Bootstrap starting.
I20260812 06:16:56.818868  8349 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:56.819810  8349 log.cc:826] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:56.821641  8349 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231: No bootstrap required, opened a new log
I20260812 06:16:56.824702  8349 raft_consensus.cc:359] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc6a3be04fce45dfb87b41c204885231" member_type: VOTER }
I20260812 06:16:56.824882  8349 raft_consensus.cc:385] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:56.824935  8349 raft_consensus.cc:740] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: dc6a3be04fce45dfb87b41c204885231, State: Initialized, Role: FOLLOWER
I20260812 06:16:56.825608  8349 consensus_queue.cc:260] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [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: "dc6a3be04fce45dfb87b41c204885231" member_type: VOTER }
I20260812 06:16:56.825776  8349 raft_consensus.cc:399] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:56.825875  8349 raft_consensus.cc:493] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:56.825999  8349 raft_consensus.cc:3060] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:56.826880  8349 raft_consensus.cc:515] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc6a3be04fce45dfb87b41c204885231" member_type: VOTER }
I20260812 06:16:56.827306  8349 leader_election.cc:304] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [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: dc6a3be04fce45dfb87b41c204885231; no voters: 
I20260812 06:16:56.827618  8349 leader_election.cc:290] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:56.827740  8353 raft_consensus.cc:2804] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:56.828022  8353 raft_consensus.cc:697] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [term 1 LEADER]: Becoming Leader. State: Replica: dc6a3be04fce45dfb87b41c204885231, State: Running, Role: LEADER
I20260812 06:16:56.828480  8353 consensus_queue.cc:237] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [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: "dc6a3be04fce45dfb87b41c204885231" member_type: VOTER }
I20260812 06:16:56.828809  8349 sys_catalog.cc:565] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:56.830482  8355 sys_catalog.cc:455] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [sys.catalog]: SysCatalogTable state changed. Reason: New leader dc6a3be04fce45dfb87b41c204885231. Latest consensus state: current_term: 1 leader_uuid: "dc6a3be04fce45dfb87b41c204885231" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc6a3be04fce45dfb87b41c204885231" member_type: VOTER } }
I20260812 06:16:56.830515  8354 sys_catalog.cc:455] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "dc6a3be04fce45dfb87b41c204885231" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc6a3be04fce45dfb87b41c204885231" member_type: VOTER } }
I20260812 06:16:56.830631  8354 sys_catalog.cc:458] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:56.830631  8355 sys_catalog.cc:458] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:56.831398  8268 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:16:56.833334  8369 catalog_manager.cc:1594] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:16:56.833425  8369 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:16:56.833493  8363 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:56.834296  8363 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:56.839236  8363 catalog_manager.cc:1383] Generated new cluster ID: b555eebe19f84c6eb7c10117023a73d5
I20260812 06:16:56.839305  8363 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:56.861894  8363 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:56.863185  8363 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:56.873538  8363 catalog_manager.cc:6092] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231: Generated new TSK 0
I20260812 06:16:56.874380  8363 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:56.896845  8268 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:56.899770  8377 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:16:56.899925  8375 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:16:56.900053  8373 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:16:56.900121  8268 server_base.cc:1061] running on GCE node
I20260812 06:16:56.900398  8268 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:56.900446  8268 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:16:56.900461  8268 hybrid_clock.cc:648] HybridClock initialized: now 1786515416900462 us; error 0 us; skew 500 ppm
I20260812 06:16:56.901512  8268 webserver.cc:533] Webserver started at http://127.8.19.1:46529/ using document root <none> and password file <none>
I20260812 06:16:56.901705  8268 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:56.901769  8268 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:56.901878  8268 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:56.902278  8268 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/instance:
uuid: "9c155bc9f5e94fa2a7a670a905419949"
format_stamp: "Formatted at 2026-08-12 06:16:56 on dist-test-slave-69rg"
I20260812 06:16:56.903784  8268 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:56.904760  8383 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:16:56.905035  8268 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:56.905138  8268 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root
uuid: "9c155bc9f5e94fa2a7a670a905419949"
format_stamp: "Formatted at 2026-08-12 06:16:56 on dist-test-slave-69rg"
I20260812 06:16:56.905210  8268 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-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:16:56.917232  8268 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:56.917738  8268 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:56.918341  8268 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:56.919229  8268 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:56.919282  8268 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:56.919349  8268 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:56.919394  8268 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:56.926622  8268 rpc_server.cc:307] RPC server started. Bound to: 127.8.19.1:40089
I20260812 06:16:56.926661  8456 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.19.1:40089 every 8 connection(s)
I20260812 06:16:56.941632  8457 heartbeater.cc:344] Connected to a master server at 127.8.19.62:35149
I20260812 06:16:56.941928  8457 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:56.942422  8457 heartbeater.cc:507] Master 127.8.19.62:35149 requested a full tablet report, sending...
I20260812 06:16:56.943755  8305 ts_manager.cc:194] Registered new tserver with Master: 9c155bc9f5e94fa2a7a670a905419949 (127.8.19.1:40089)
I20260812 06:16:56.943954  8268 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01667079s
I20260812 06:16:56.945250  8305 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45366
I20260812 06:16:56.954002  8305 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45374:
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:16:56.967811  8413 tablet_service.cc:1511] Processing CreateTablet for tablet 116658a07dd64a76bad86771db4ae6a6 (DEFAULT_TABLE table=heavy-update-compaction-test [id=91d52159aff148709ed6d88dd0b4b2b7]), partition=
I20260812 06:16:56.968302  8413 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 116658a07dd64a76bad86771db4ae6a6. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:56.970916  8470 tablet_bootstrap.cc:492] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Bootstrap starting.
I20260812 06:16:56.972047  8470 tablet_bootstrap.cc:654] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:56.973222  8470 tablet_bootstrap.cc:492] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: No bootstrap required, opened a new log
I20260812 06:16:56.973351  8470 ts_tablet_manager.cc:1403] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:56.973786  8470 raft_consensus.cc:359] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9c155bc9f5e94fa2a7a670a905419949" member_type: VOTER last_known_addr { host: "127.8.19.1" port: 40089 } }
I20260812 06:16:56.973959  8470 raft_consensus.cc:385] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:56.974010  8470 raft_consensus.cc:740] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9c155bc9f5e94fa2a7a670a905419949, State: Initialized, Role: FOLLOWER
I20260812 06:16:56.974153  8470 consensus_queue.cc:260] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949 [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: "9c155bc9f5e94fa2a7a670a905419949" member_type: VOTER last_known_addr { host: "127.8.19.1" port: 40089 } }
I20260812 06:16:56.974262  8470 raft_consensus.cc:399] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:56.974354  8470 raft_consensus.cc:493] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:56.974413  8470 raft_consensus.cc:3060] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:56.975137  8470 raft_consensus.cc:515] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9c155bc9f5e94fa2a7a670a905419949" member_type: VOTER last_known_addr { host: "127.8.19.1" port: 40089 } }
I20260812 06:16:56.975275  8470 leader_election.cc:304] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949 [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: 9c155bc9f5e94fa2a7a670a905419949; no voters: 
I20260812 06:16:56.975524  8470 leader_election.cc:290] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:56.975796  8472 raft_consensus.cc:2804] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:56.975885  8470 ts_tablet_manager.cc:1434] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:16:56.976070  8472 raft_consensus.cc:697] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949 [term 1 LEADER]: Becoming Leader. State: Replica: 9c155bc9f5e94fa2a7a670a905419949, State: Running, Role: LEADER
I20260812 06:16:56.976332  8457 heartbeater.cc:499] Master 127.8.19.62:35149 was elected leader, sending a full tablet report...
I20260812 06:16:56.976269  8472 consensus_queue.cc:237] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949 [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: "9c155bc9f5e94fa2a7a670a905419949" member_type: VOTER last_known_addr { host: "127.8.19.1" port: 40089 } }
I20260812 06:16:56.979135  8305 catalog_manager.cc:5719] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949 reported cstate change: term changed from 0 to 1, leader changed from <none> to 9c155bc9f5e94fa2a7a670a905419949 (127.8.19.1). New cstate: current_term: 1 leader_uuid: "9c155bc9f5e94fa2a7a670a905419949" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9c155bc9f5e94fa2a7a670a905419949" member_type: VOTER last_known_addr { host: "127.8.19.1" port: 40089 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:57.046017  8268 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.023s	sys 0.004s
I20260812 06:16:57.177742  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushMRSOp(116658a07dd64a76bad86771db4ae6a6): perf score=19.054940
I20260812 06:16:57.357599  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushMRSOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.179s	user 0.135s	sys 0.040s Metrics: {"bytes_written":12717736,"cfile_init":1,"compiler_manager_pool.queue_time_us":195,"delete_count":0,"dirs.queue_time_us":585,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":1511,"drs_written":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45918,"lbm_writes_lt_1ms":767,"mutex_wait_us":179,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":412928,"thread_start_us":128,"threads_started":1,"update_count":1550}
I20260812 06:16:57.358939  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling LogGCOp(116658a07dd64a76bad86771db4ae6a6): free 20743880 bytes of WAL
I20260812 06:16:57.359258  8388 log_reader.cc:385] T 116658a07dd64a76bad86771db4ae6a6: removed 2 log segments from log reader
I20260812 06:16:57.359342  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000001 (ops 1-6)
I20260812 06:16:57.359405  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000002 (ops 7-11)
I20260812 06:16:57.364944  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: LogGCOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:16:57.365403  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:16:57.386060  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.020s	user 0.009s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5520,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.386581  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:16:57.401660  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5804,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:57.402176  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling UndoDeltaBlockGCOp(116658a07dd64a76bad86771db4ae6a6): 16411392 bytes on disk
I20260812 06:16:57.402851  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: UndoDeltaBlockGCOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:16:57.403350  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:16:57.573506  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.170s	user 0.133s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":443,"lbm_read_time_us":12590,"lbm_reads_lt_1ms":569,"lbm_write_time_us":27157,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15104,"thread_start_us":330,"threads_started":5,"update_count":2500}
I20260812 06:16:57.574136  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=10.126437
I20260812 06:16:57.610057  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.036s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14553,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:57.610524  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:16:57.631932  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.021s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5955,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.632419  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:16:57.767066  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.134s	user 0.125s	sys 0.009s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":270,"lbm_read_time_us":8909,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26649,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":2000}
I20260812 06:16:57.767738  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=10.126437
I20260812 06:16:57.806970  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.039s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17453,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:57.807520  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:16:57.818933  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3995,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.820011  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:16:57.945546  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.125s	user 0.089s	sys 0.036s 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":216,"lbm_read_time_us":9596,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23465,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2000}
I20260812 06:16:57.946178  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=10.126437
I20260812 06:16:57.991819  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.045s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15287,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:57.992331  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:16:58.003448  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.004071  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:16:58.129326  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.125s	user 0.113s	sys 0.012s 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":1091,"lbm_read_time_us":7784,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23852,"lbm_writes_lt_1ms":443,"mutex_wait_us":377,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:58.130102  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=10.126437
I20260812 06:16:58.176669  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.046s	user 0.020s	sys 0.024s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17104,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:58.177289  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:16:58.189085  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4781,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.189554  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:16:58.353633  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.164s	user 0.092s	sys 0.072s 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":538,"lbm_read_time_us":12466,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28134,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:16:58.357172  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=11.118625
I20260812 06:16:58.386583  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.029s	user 0.018s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12918,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:58.387027  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:16:58.400380  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4814,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:58.400898  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:16:58.530761  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.130s	user 0.094s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":194,"lbm_read_time_us":9369,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24203,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":59904,"update_count":2000}
I20260812 06:16:58.531567  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=11.118625
I20260812 06:16:58.572536  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.041s	user 0.035s	sys 0.005s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":18333,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:58.573060  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:16:58.583695  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3805,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:58.584157  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushMRSOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:16:58.611727  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushMRSOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.027s	user 0.018s	sys 0.008s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":1342,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1636,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:58.612506  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling LogGCOp(116658a07dd64a76bad86771db4ae6a6): free 112692365 bytes of WAL
I20260812 06:16:58.612722  8388 log_reader.cc:385] T 116658a07dd64a76bad86771db4ae6a6: removed 11 log segments from log reader
I20260812 06:16:58.612779  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000003 (ops 12-16)
I20260812 06:16:58.612830  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000004 (ops 17-21)
I20260812 06:16:58.612885  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000005 (ops 22-26)
I20260812 06:16:58.612926  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000006 (ops 27-31)
I20260812 06:16:58.612962  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000007 (ops 32-36)
I20260812 06:16:58.612999  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000008 (ops 37-41)
I20260812 06:16:58.613035  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000009 (ops 42-46)
I20260812 06:16:58.613072  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000010 (ops 47-51)
I20260812 06:16:58.613114  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000011 (ops 52-56)
I20260812 06:16:58.613157  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000012 (ops 57-61)
I20260812 06:16:58.613193  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000013 (ops 62-66)
I20260812 06:16:58.637863  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: LogGCOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.025s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:16:58.638345  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=3.181125
I20260812 06:16:58.657078  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.019s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7100,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:58.657595  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling UndoDeltaBlockGCOp(116658a07dd64a76bad86771db4ae6a6): 462 bytes on disk
I20260812 06:16:58.658229  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: UndoDeltaBlockGCOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":111,"lbm_reads_lt_1ms":4}
I20260812 06:16:58.658879  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:16:58.668995  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3806,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:58.669703  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:16:58.853245  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.183s	user 0.133s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877322,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":360,"lbm_read_time_us":13150,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35765,"lbm_writes_lt_1ms":643,"mutex_wait_us":55,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:16:58.854002  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=14.095187
I20260812 06:16:58.904649  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.050s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20121,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:58.905193  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:16:58.915829  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4188,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.916536  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:16:59.069988  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.153s	user 0.125s	sys 0.024s 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":632,"lbm_read_time_us":9988,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31567,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:16:59.070606  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=14.095187
I20260812 06:16:59.122220  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.051s	user 0.025s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22769,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.122727  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:16:59.133607  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4038,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.134150  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:16:59.281870  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.147s	user 0.106s	sys 0.040s 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":391,"lbm_read_time_us":10891,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31433,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:16:59.282547  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=10.126437
I20260812 06:16:59.318521  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.033s	user 0.027s	sys 0.003s Metrics: {"bytes_written":12635684,"delete_count":0,"lbm_write_time_us":13548,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1540}
I20260812 06:16:59.319000  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:16:59.328996  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":3700,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:16:59.329504  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:16:59.460623  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.131s	user 0.105s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1273,"lbm_read_time_us":8497,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25630,"lbm_writes_lt_1ms":443,"mutex_wait_us":332,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:59.461289  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=10.126437
I20260812 06:16:59.515045  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.054s	user 0.019s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14046,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:59.515707  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:16:59.526358  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4156,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.526844  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:16:59.679191  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.152s	user 0.116s	sys 0.036s 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":285,"lbm_read_time_us":11115,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24603,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.679884  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=10.126437
I20260812 06:16:59.727619  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.048s	user 0.028s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18969,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:59.728104  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:16:59.739300  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4382,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.739856  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:16:59.868301  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.128s	user 0.082s	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":177,"lbm_read_time_us":9622,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25237,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:16:59.868966  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=10.126437
I20260812 06:16:59.919952  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.051s	user 0.037s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18221,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:59.920545  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:16:59.932832  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4359,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.933346  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushMRSOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:16:59.960184  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushMRSOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":1412,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1522,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:59.960886  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling LogGCOp(116658a07dd64a76bad86771db4ae6a6): free 124257196 bytes of WAL
I20260812 06:16:59.961112  8388 log_reader.cc:385] T 116658a07dd64a76bad86771db4ae6a6: removed 12 log segments from log reader
I20260812 06:16:59.961155  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000014 (ops 67-71)
I20260812 06:16:59.961215  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000015 (ops 72-76)
I20260812 06:16:59.961259  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000016 (ops 77-81)
I20260812 06:16:59.961303  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000017 (ops 82-86)
I20260812 06:16:59.961341  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000018 (ops 87-90)
I20260812 06:16:59.961383  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000019 (ops 91-95)
I20260812 06:16:59.961426  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000020 (ops 96-100)
I20260812 06:16:59.961465  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000021 (ops 101-105)
I20260812 06:16:59.961503  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000022 (ops 106-110)
I20260812 06:16:59.961542  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000023 (ops 111-115)
I20260812 06:16:59.961580  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000024 (ops 116-120)
I20260812 06:16:59.961618  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000025 (ops 121-125)
I20260812 06:16:59.988533  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: LogGCOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:16:59.988891  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=3.181125
I20260812 06:17:00.000614  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4542,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:00.001205  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:17:00.012785  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3827,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:00.013348  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:17:00.186452  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.173s	user 0.141s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":519,"lbm_read_time_us":12782,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35397,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":42240,"thread_start_us":93,"threads_started":1,"update_count":3000}
I20260812 06:17:00.187187  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=14.095187
I20260812 06:17:00.240175  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.053s	user 0.009s	sys 0.041s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":25494,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.240633  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling UndoDeltaBlockGCOp(116658a07dd64a76bad86771db4ae6a6): 447 bytes on disk
I20260812 06:17:00.241057  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: UndoDeltaBlockGCOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:17:00.241580  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:17:00.253257  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4516,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.253719  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:17:00.412752  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.159s	user 0.124s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":218,"lbm_read_time_us":10966,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31444,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:17:00.413443  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=14.095187
I20260812 06:17:00.466143  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.053s	user 0.033s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24801,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.466720  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:17:00.479120  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.012s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4449,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.479619  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:17:00.635448  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.156s	user 0.120s	sys 0.029s 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":1127,"lbm_read_time_us":11333,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29414,"lbm_writes_lt_1ms":543,"mutex_wait_us":278,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:17:00.636155  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=11.118625
I20260812 06:17:00.676478  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.040s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17167,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:00.677280  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:17:00.691560  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.014s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4264,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:00.692142  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:17:00.822515  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.130s	user 0.110s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":89,"lbm_read_time_us":9137,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27336,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:00.823076  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=10.126437
I20260812 06:17:00.867847  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.045s	user 0.012s	sys 0.031s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15141,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:00.868569  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:17:00.886873  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.018s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7016,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.887485  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:17:01.032641  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.145s	user 0.106s	sys 0.039s 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":994,"lbm_read_time_us":10687,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23856,"lbm_writes_lt_1ms":443,"mutex_wait_us":312,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":48640,"update_count":2000}
I20260812 06:17:01.033272  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=10.126437
I20260812 06:17:01.071939  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.038s	user 0.026s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16131,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:01.072479  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:17:01.088032  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6037,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.088686  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:17:01.213680  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.125s	user 0.105s	sys 0.020s 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":155,"lbm_read_time_us":9035,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24917,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:17:01.214442  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=10.126437
I20260812 06:17:01.258389  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.044s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16538,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:01.259075  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:17:01.271996  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4761,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.272512  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushMRSOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:17:01.299966  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushMRSOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1319,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1710,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:01.300714  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling LogGCOp(116658a07dd64a76bad86771db4ae6a6): free 112692652 bytes of WAL
I20260812 06:17:01.300992  8388 log_reader.cc:385] T 116658a07dd64a76bad86771db4ae6a6: removed 11 log segments from log reader
I20260812 06:17:01.301052  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000026 (ops 126-130)
I20260812 06:17:01.301095  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000027 (ops 131-135)
I20260812 06:17:01.301131  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000028 (ops 136-140)
I20260812 06:17:01.301160  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000029 (ops 141-145)
I20260812 06:17:01.301189  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000030 (ops 146-150)
I20260812 06:17:01.301218  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000031 (ops 151-155)
I20260812 06:17:01.301252  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000032 (ops 156-160)
I20260812 06:17:01.301286  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000033 (ops 161-165)
I20260812 06:17:01.301316  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000034 (ops 166-170)
I20260812 06:17:01.301342  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000035 (ops 171-175)
I20260812 06:17:01.301371  8388 log.cc:1079] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/116658a07dd64a76bad86771db4ae6a6/wal-000000036 (ops 176-180)
I20260812 06:17:01.327114  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: LogGCOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:01.327512  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:17:01.351212  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.024s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4515,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.351727  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:17:01.363360  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4388,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.364251  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling UndoDeltaBlockGCOp(116658a07dd64a76bad86771db4ae6a6): 448 bytes on disk
I20260812 06:17:01.364892  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: UndoDeltaBlockGCOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4}
I20260812 06:17:01.365401  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:17:01.535979  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.170s	user 0.131s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877340,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":559,"lbm_read_time_us":11362,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36156,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:17:01.536664  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=14.095187
I20260812 06:17:01.591322  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.054s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22651,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.591806  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:17:01.602916  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4123,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.603614  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:17:01.773344  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.169s	user 0.117s	sys 0.052s 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":795,"lbm_read_time_us":10388,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35734,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:17:01.773957  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=11.118625
I20260812 06:17:01.793442  8268 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.747s	user 1.711s	sys 0.163s
I20260812 06:17:01.817239  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.043s	user 0.023s	sys 0.017s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":23412,"lbm_writes_1-10_ms":5,"lbm_writes_lt_1ms":308,"reinsert_count":0,"update_count":1550}
I20260812 06:17:01.817875  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6): perf score=2.188937
I20260812 06:17:01.833493  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: FlushDeltaMemStoresOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5860,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:01.834107  8458 maintenance_manager.cc:419] P 9c155bc9f5e94fa2a7a670a905419949: Scheduling MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6): perf score=1.000000
I20260812 06:17:01.834199  8268 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.040s	user 0.004s	sys 0.000s
I20260812 06:17:01.834879  8268 tablet_server.cc:179] TabletServer@127.8.19.1:0 shutting down...
I20260812 06:17:01.949553  8388 maintenance_manager.cc:643] P 9c155bc9f5e94fa2a7a670a905419949: MajorDeltaCompactionOp(116658a07dd64a76bad86771db4ae6a6) complete. Timing: real 0.115s	user 0.086s	sys 0.029s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":402,"cfile_cache_miss_bytes":16409877,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1358,"lbm_read_time_us":6489,"lbm_reads_lt_1ms":418,"lbm_write_time_us":21884,"lbm_writes_lt_1ms":443,"mutex_wait_us":390,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2000}
I20260812 06:17:01.950394  8268 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:01.950865  8268 tablet_replica.cc:333] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949: stopping tablet replica
I20260812 06:17:01.951138  8268 raft_consensus.cc:2243] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:01.951391  8268 raft_consensus.cc:2272] T 116658a07dd64a76bad86771db4ae6a6 P 9c155bc9f5e94fa2a7a670a905419949 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:01.956851  8268 tablet_server.cc:196] TabletServer@127.8.19.1:0 shutdown complete.
I20260812 06:17:01.989347  8268 master.cc:562] Master@127.8.19.62:35149 shutting down...
I20260812 06:17:01.993465  8268 raft_consensus.cc:2243] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:01.993654  8268 raft_consensus.cc:2272] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:01.993709  8268 tablet_replica.cc:333] T 00000000000000000000000000000000 P dc6a3be04fce45dfb87b41c204885231: stopping tablet replica
I20260812 06:17:02.006414  8268 master.cc:584] Master@127.8.19.62:35149 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5347 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:02.102957  8268 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.19.62:36305
I20260812 06:17:02.103426  8268 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:02.105679  8495 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:02.105868  8268 server_base.cc:1061] running on GCE node
W20260812 06:17:02.105758  8490 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:02.105670  8491 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:02.106154  8268 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:02.106204  8268 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:02.106220  8268 hybrid_clock.cc:648] HybridClock initialized: now 1786515422106221 us; error 0 us; skew 500 ppm
I20260812 06:17:02.107012  8268 webserver.cc:533] Webserver started at http://127.8.19.62:33175/ using document root <none> and password file <none>
I20260812 06:17:02.107151  8268 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:02.107197  8268 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:02.107250  8268 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:02.107609  8268 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/master-0-root/instance:
uuid: "3d27ac348d864439af651d356e60338a"
format_stamp: "Formatted at 2026-08-12 06:17:02 on dist-test-slave-69rg"
I20260812 06:17:02.109127  8268 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:02.110070  8500 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:02.110391  8268 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:02.110484  8268 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/master-0-root
uuid: "3d27ac348d864439af651d356e60338a"
format_stamp: "Formatted at 2026-08-12 06:17:02 on dist-test-slave-69rg"
I20260812 06:17:02.110566  8268 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:02.119323  8268 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:02.119704  8268 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:02.123971  8268 rpc_server.cc:307] RPC server started. Bound to: 127.8.19.62:36305
I20260812 06:17:02.127892  8562 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.19.62:36305 every 8 connection(s)
I20260812 06:17:02.129038  8563 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:02.132406  8563 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a: Bootstrap starting.
I20260812 06:17:02.133173  8563 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:02.134256  8563 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a: No bootstrap required, opened a new log
I20260812 06:17:02.134624  8563 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3d27ac348d864439af651d356e60338a" member_type: VOTER }
I20260812 06:17:02.134708  8563 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:02.134732  8563 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3d27ac348d864439af651d356e60338a, State: Initialized, Role: FOLLOWER
I20260812 06:17:02.134837  8563 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [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: "3d27ac348d864439af651d356e60338a" member_type: VOTER }
I20260812 06:17:02.134896  8563 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:02.134918  8563 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:02.134953  8563 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:02.135599  8563 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3d27ac348d864439af651d356e60338a" member_type: VOTER }
I20260812 06:17:02.135710  8563 leader_election.cc:304] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [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: 3d27ac348d864439af651d356e60338a; no voters: 
I20260812 06:17:02.135867  8563 leader_election.cc:290] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:02.136013  8567 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:02.136212  8567 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [term 1 LEADER]: Becoming Leader. State: Replica: 3d27ac348d864439af651d356e60338a, State: Running, Role: LEADER
I20260812 06:17:02.136375  8567 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [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: "3d27ac348d864439af651d356e60338a" member_type: VOTER }
I20260812 06:17:02.136384  8563 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:02.136819  8568 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3d27ac348d864439af651d356e60338a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3d27ac348d864439af651d356e60338a" member_type: VOTER } }
I20260812 06:17:02.136854  8569 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3d27ac348d864439af651d356e60338a. Latest consensus state: current_term: 1 leader_uuid: "3d27ac348d864439af651d356e60338a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3d27ac348d864439af651d356e60338a" member_type: VOTER } }
I20260812 06:17:02.136933  8569 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:02.137233  8571 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:02.137200  8568 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:02.138454  8571 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:02.138641  8268 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:02.140305  8571 catalog_manager.cc:1383] Generated new cluster ID: 59566645de1c4640b9887df6055b0fb0
I20260812 06:17:02.140372  8571 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:02.148675  8571 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:02.149273  8571 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:02.154461  8571 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a: Generated new TSK 0
I20260812 06:17:02.154677  8571 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:02.171180  8268 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:02.173516  8590 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:02.173533  8587 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:02.173687  8268 server_base.cc:1061] running on GCE node
W20260812 06:17:02.173734  8586 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:02.174113  8268 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:02.174181  8268 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:02.174240  8268 hybrid_clock.cc:648] HybridClock initialized: now 1786515422174239 us; error 0 us; skew 500 ppm
I20260812 06:17:02.175181  8268 webserver.cc:533] Webserver started at http://127.8.19.1:45711/ using document root <none> and password file <none>
I20260812 06:17:02.175407  8268 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:02.175484  8268 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:02.175568  8268 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:02.176066  8268 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/instance:
uuid: "0138e7adb6b14ba19635a77ad0aee470"
format_stamp: "Formatted at 2026-08-12 06:17:02 on dist-test-slave-69rg"
I20260812 06:17:02.177667  8268 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:02.178818  8596 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:02.179184  8268 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:02.179270  8268 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root
uuid: "0138e7adb6b14ba19635a77ad0aee470"
format_stamp: "Formatted at 2026-08-12 06:17:02 on dist-test-slave-69rg"
I20260812 06:17:02.179337  8268 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:02.194950  8268 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:02.195335  8268 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:02.195621  8268 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:02.196156  8268 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:02.196197  8268 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:02.196257  8268 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:02.196296  8268 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:02.200775  8268 rpc_server.cc:307] RPC server started. Bound to: 127.8.19.1:34893
I20260812 06:17:02.203265  8670 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.19.1:34893 every 8 connection(s)
I20260812 06:17:02.216285  8671 heartbeater.cc:344] Connected to a master server at 127.8.19.62:36305
I20260812 06:17:02.216449  8671 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:02.216742  8671 heartbeater.cc:507] Master 127.8.19.62:36305 requested a full tablet report, sending...
I20260812 06:17:02.217468  8521 ts_manager.cc:194] Registered new tserver with Master: 0138e7adb6b14ba19635a77ad0aee470 (127.8.19.1:34893)
I20260812 06:17:02.218202  8268 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016621349s
I20260812 06:17:02.218375  8521 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37286
I20260812 06:17:02.225991  8521 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37288:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:02.234966  8627 tablet_service.cc:1511] Processing CreateTablet for tablet b852673544c54f23bf98cc1270a88646 (DEFAULT_TABLE table=heavy-update-compaction-test [id=9821a86f7a8f49bcae5eff36b2ccd60c]), partition=
I20260812 06:17:02.235225  8627 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b852673544c54f23bf98cc1270a88646. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:02.237246  8686 tablet_bootstrap.cc:492] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Bootstrap starting.
I20260812 06:17:02.238392  8686 tablet_bootstrap.cc:654] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:02.239530  8686 tablet_bootstrap.cc:492] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: No bootstrap required, opened a new log
I20260812 06:17:02.239624  8686 ts_tablet_manager.cc:1403] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:02.239948  8686 raft_consensus.cc:359] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0138e7adb6b14ba19635a77ad0aee470" member_type: VOTER last_known_addr { host: "127.8.19.1" port: 34893 } }
I20260812 06:17:02.240029  8686 raft_consensus.cc:385] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:02.240072  8686 raft_consensus.cc:740] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0138e7adb6b14ba19635a77ad0aee470, State: Initialized, Role: FOLLOWER
I20260812 06:17:02.240204  8686 consensus_queue.cc:260] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470 [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: "0138e7adb6b14ba19635a77ad0aee470" member_type: VOTER last_known_addr { host: "127.8.19.1" port: 34893 } }
I20260812 06:17:02.240298  8686 raft_consensus.cc:399] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:02.240355  8686 raft_consensus.cc:493] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:02.240406  8686 raft_consensus.cc:3060] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:02.241240  8686 raft_consensus.cc:515] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0138e7adb6b14ba19635a77ad0aee470" member_type: VOTER last_known_addr { host: "127.8.19.1" port: 34893 } }
I20260812 06:17:02.241384  8686 leader_election.cc:304] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470 [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: 0138e7adb6b14ba19635a77ad0aee470; no voters: 
I20260812 06:17:02.241618  8686 leader_election.cc:290] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:02.241740  8688 raft_consensus.cc:2804] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:02.241992  8671 heartbeater.cc:499] Master 127.8.19.62:36305 was elected leader, sending a full tablet report...
I20260812 06:17:02.241999  8688 raft_consensus.cc:697] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470 [term 1 LEADER]: Becoming Leader. State: Replica: 0138e7adb6b14ba19635a77ad0aee470, State: Running, Role: LEADER
I20260812 06:17:02.242002  8686 ts_tablet_manager.cc:1434] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:17:02.242174  8688 consensus_queue.cc:237] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470 [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: "0138e7adb6b14ba19635a77ad0aee470" member_type: VOTER last_known_addr { host: "127.8.19.1" port: 34893 } }
I20260812 06:17:02.243551  8521 catalog_manager.cc:5719] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470 reported cstate change: term changed from 0 to 1, leader changed from <none> to 0138e7adb6b14ba19635a77ad0aee470 (127.8.19.1). New cstate: current_term: 1 leader_uuid: "0138e7adb6b14ba19635a77ad0aee470" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0138e7adb6b14ba19635a77ad0aee470" member_type: VOTER last_known_addr { host: "127.8.19.1" port: 34893 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:02.305187  8268 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.014s	sys 0.008s
I20260812 06:17:02.453804  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushMRSOp(b852673544c54f23bf98cc1270a88646): perf score=19.054940
I20260812 06:17:02.613718  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushMRSOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.160s	user 0.102s	sys 0.053s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":173,"dirs.run_wall_time_us":825,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39492,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:17:02.614490  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling LogGCOp(b852673544c54f23bf98cc1270a88646): free 20743880 bytes of WAL
I20260812 06:17:02.614769  8601 log_reader.cc:385] T b852673544c54f23bf98cc1270a88646: removed 2 log segments from log reader
I20260812 06:17:02.614817  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000001 (ops 1-6)
I20260812 06:17:02.614848  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000002 (ops 7-11)
I20260812 06:17:02.619233  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: LogGCOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:02.619755  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:02.631850  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4407,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.632364  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:02.790975  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.158s	user 0.103s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":439,"lbm_read_time_us":11107,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24397,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":302,"threads_started":5,"update_count":2000}
I20260812 06:17:02.791673  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=11.118625
I20260812 06:17:02.848874  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.057s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":22486,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:17:02.849416  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=6.157687
I20260812 06:17:02.876137  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.027s	user 0.010s	sys 0.011s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":9880,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:02.876588  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:03.058315  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.182s	user 0.134s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":647,"lbm_read_time_us":13746,"lbm_reads_lt_1ms":568,"lbm_write_time_us":27917,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:17:03.058976  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling UndoDeltaBlockGCOp(b852673544c54f23bf98cc1270a88646): 16411395 bytes on disk
I20260812 06:17:03.059502  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: UndoDeltaBlockGCOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":97,"lbm_reads_lt_1ms":4}
I20260812 06:17:03.060027  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=14.095187
I20260812 06:17:03.115342  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.055s	user 0.029s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22455,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.115789  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:03.126125  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4009,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.126796  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:03.307401  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.180s	user 0.129s	sys 0.042s 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":198,"lbm_read_time_us":9410,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27997,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":40192,"update_count":2500}
I20260812 06:17:03.308082  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=14.095187
I20260812 06:17:03.360684  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.052s	user 0.037s	sys 0.004s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18940,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.361148  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:03.372349  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4027,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.372851  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:03.543457  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.170s	user 0.134s	sys 0.024s 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":147,"lbm_read_time_us":9716,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32885,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:03.544267  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=14.095187
I20260812 06:17:03.600988  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.057s	user 0.022s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19916,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.601473  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:03.613523  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4148,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.614058  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:03.776854  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.163s	user 0.106s	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":142,"lbm_read_time_us":11732,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30852,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:17:03.777637  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=14.095187
I20260812 06:17:03.830315  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.052s	user 0.033s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23316,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.830915  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:03.843840  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5066,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.844328  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushMRSOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:03.877756  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushMRSOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.033s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":267,"dirs.run_wall_time_us":1415,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2047,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:03.878445  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling LogGCOp(b852673544c54f23bf98cc1270a88646): free 115943176 bytes of WAL
I20260812 06:17:03.878682  8601 log_reader.cc:385] T b852673544c54f23bf98cc1270a88646: removed 11 log segments from log reader
I20260812 06:17:03.878728  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000003 (ops 12-16)
I20260812 06:17:03.878756  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000004 (ops 17-21)
I20260812 06:17:03.878820  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000005 (ops 22-26)
I20260812 06:17:03.878854  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000006 (ops 27-31)
I20260812 06:17:03.878888  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000007 (ops 32-36)
I20260812 06:17:03.878917  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000008 (ops 37-41)
I20260812 06:17:03.878960  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000009 (ops 42-46)
I20260812 06:17:03.878997  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000010 (ops 47-51)
I20260812 06:17:03.879035  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000011 (ops 52-56)
I20260812 06:17:03.879073  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000012 (ops 57-61)
I20260812 06:17:03.879112  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000013 (ops 62-66)
I20260812 06:17:03.905543  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: LogGCOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.027s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:03.906114  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling UndoDeltaBlockGCOp(b852673544c54f23bf98cc1270a88646): 462 bytes on disk
I20260812 06:17:03.906607  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: UndoDeltaBlockGCOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:17:03.907161  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=5.165500
I20260812 06:17:03.928318  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.021s	user 0.006s	sys 0.013s Metrics: {"bytes_written":6646161,"delete_count":0,"lbm_write_time_us":8578,"lbm_writes_lt_1ms":165,"reinsert_count":0,"update_count":810}
I20260812 06:17:03.928848  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:03.937119  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.008s	user 0.000s	sys 0.007s Metrics: {"bytes_written":1559102,"delete_count":0,"lbm_write_time_us":2694,"lbm_writes_lt_1ms":41,"reinsert_count":0,"update_count":190}
I20260812 06:17:03.937805  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:04.182651  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.245s	user 0.169s	sys 0.063s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979691,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":507,"lbm_read_time_us":15149,"lbm_reads_lt_1ms":766,"lbm_write_time_us":40293,"lbm_writes_lt_1ms":743,"mutex_wait_us":39,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":33664,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:17:04.183571  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=18.063937
I20260812 06:17:04.265898  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.082s	user 0.027s	sys 0.050s Metrics: {"bytes_written":20512311,"delete_count":0,"lbm_write_time_us":30410,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:04.266511  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:04.278419  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4549,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.278882  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:04.480827  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.202s	user 0.129s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1076,"lbm_read_time_us":14894,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34137,"lbm_writes_lt_1ms":643,"mutex_wait_us":298,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":3000}
I20260812 06:17:04.481662  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=14.095187
I20260812 06:17:04.531906  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.050s	user 0.024s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22668,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:04.532511  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:04.548550  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6346,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.549106  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:04.727926  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.179s	user 0.098s	sys 0.080s 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":259,"lbm_read_time_us":12898,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32400,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:17:04.728726  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=14.095187
I20260812 06:17:04.786369  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.057s	user 0.033s	sys 0.024s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20789,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:04.786975  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:04.797755  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4314,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.798275  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:04.974750  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.176s	user 0.137s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1304,"lbm_read_time_us":12685,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28152,"lbm_writes_lt_1ms":543,"mutex_wait_us":384,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:17:04.975338  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=11.118625
I20260812 06:17:05.014145  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.039s	user 0.035s	sys 0.003s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16670,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:05.014887  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:05.039919  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.025s	user 0.014s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5187,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:05.041056  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:05.199051  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.158s	user 0.099s	sys 0.052s 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":154,"lbm_read_time_us":11313,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23765,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2000}
I20260812 06:17:05.199755  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=14.095187
I20260812 06:17:05.257989  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.058s	user 0.038s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23898,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:05.258558  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:05.269371  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3991,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:05.270120  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:05.446022  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.176s	user 0.131s	sys 0.036s 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":663,"lbm_read_time_us":10587,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33445,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":72576,"update_count":2500}
I20260812 06:17:05.446771  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=14.095187
I20260812 06:17:05.499046  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.052s	user 0.019s	sys 0.032s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":23083,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:05.499624  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:05.515825  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6120,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:05.516383  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushMRSOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:05.550405  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushMRSOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.034s	user 0.029s	sys 0.003s Metrics: {"bytes_written":1357580,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1403,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1728,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:17:05.551481  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling LogGCOp(b852673544c54f23bf98cc1270a88646): free 129320458 bytes of WAL
I20260812 06:17:05.551847  8601 log_reader.cc:385] T b852673544c54f23bf98cc1270a88646: removed 13 log segments from log reader
I20260812 06:17:05.551981  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000014 (ops 67-71)
I20260812 06:17:05.552078  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000015 (ops 72-76)
I20260812 06:17:05.552158  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000016 (ops 77-81)
I20260812 06:17:05.552289  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000017 (ops 82-86)
I20260812 06:17:05.552381  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000018 (ops 87-90)
I20260812 06:17:05.552439  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000019 (ops 91-95)
I20260812 06:17:05.552500  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000020 (ops 96-100)
I20260812 06:17:05.552582  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000021 (ops 101-105)
I20260812 06:17:05.552678  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000022 (ops 106-110)
I20260812 06:17:05.552757  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000023 (ops 111-114)
I20260812 06:17:05.552842  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000024 (ops 115-119)
I20260812 06:17:05.552938  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000025 (ops 120-124)
I20260812 06:17:05.553035  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000026 (ops 125-129)
I20260812 06:17:05.584862  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: LogGCOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:05.585350  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=6.157687
I20260812 06:17:05.611232  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.026s	user 0.016s	sys 0.007s Metrics: {"bytes_written":8040982,"delete_count":0,"lbm_write_time_us":10486,"lbm_writes_lt_1ms":199,"reinsert_count":0,"update_count":980}
I20260812 06:17:05.611742  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling LogGCOp(b852673544c54f23bf98cc1270a88646): free 8767197 bytes of WAL
I20260812 06:17:05.611945  8601 log_reader.cc:385] T b852673544c54f23bf98cc1270a88646: removed 1 log segments from log reader
I20260812 06:17:05.611991  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000027 (ops 130-134)
I20260812 06:17:05.613777  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: LogGCOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:05.614125  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling UndoDeltaBlockGCOp(b852673544c54f23bf98cc1270a88646): 508 bytes on disk
I20260812 06:17:05.614560  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: UndoDeltaBlockGCOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:17:05.615037  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:05.847345  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.232s	user 0.153s	sys 0.074s Metrics: {"cfile_cache_miss":729,"cfile_cache_miss_bytes":32815540,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":226,"lbm_read_time_us":14165,"lbm_reads_lt_1ms":765,"lbm_write_time_us":40488,"lbm_writes_lt_1ms":739,"mutex_wait_us":1,"peak_mem_usage":86764520,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":78,"threads_started":1,"update_count":3480}
I20260812 06:17:05.848069  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=19.056125
I20260812 06:17:05.920370  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.072s	user 0.037s	sys 0.032s Metrics: {"bytes_written":20676416,"delete_count":0,"lbm_write_time_us":27242,"lbm_writes_lt_1ms":507,"reinsert_count":0,"update_count":2520}
I20260812 06:17:05.920996  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:05.932507  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4790,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:05.932958  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:06.137740  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.205s	user 0.148s	sys 0.056s Metrics: {"cfile_cache_miss":636,"cfile_cache_miss_bytes":29041203,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":243,"lbm_read_time_us":15370,"lbm_reads_lt_1ms":676,"lbm_write_time_us":34204,"lbm_writes_lt_1ms":647,"mutex_wait_us":27,"peak_mem_usage":75706612,"reinsert_count":0,"spinlock_wait_cycles":20096,"update_count":3020}
I20260812 06:17:06.138564  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=14.095187
I20260812 06:17:06.185298  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.046s	user 0.019s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19131,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:06.186038  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:06.202463  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.016s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6179,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.203285  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:06.365378  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.162s	user 0.106s	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":340,"lbm_read_time_us":12699,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26436,"lbm_writes_lt_1ms":543,"mutex_wait_us":83,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2500}
I20260812 06:17:06.366140  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=14.095187
I20260812 06:17:06.423388  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.057s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19764,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:06.424039  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:06.435127  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.011s	user 0.005s	sys 0.004s 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:17:06.435622  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:06.607380  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.172s	user 0.108s	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":722,"lbm_read_time_us":11107,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29179,"lbm_writes_lt_1ms":543,"mutex_wait_us":260,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:17:06.608039  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=14.095187
I20260812 06:17:06.667970  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.060s	user 0.030s	sys 0.024s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":20484,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:06.668565  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:06.680611  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4848,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.681118  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:06.882824  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.202s	user 0.124s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":971,"lbm_read_time_us":13520,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31871,"lbm_writes_lt_1ms":543,"mutex_wait_us":272,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:17:06.883430  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=14.095187
I20260812 06:17:06.934854  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.051s	user 0.014s	sys 0.031s Metrics: {"bytes_written":16409882,"delete_count":0,"lbm_write_time_us":20961,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:06.935488  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:06.946345  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4150,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.947137  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:07.147819  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.201s	user 0.123s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774669,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":178,"lbm_read_time_us":12026,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31767,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":2500}
I20260812 06:17:07.148586  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=14.095187
I20260812 06:17:07.193953  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.045s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19277,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:07.194502  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:07.207747  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.013s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5029,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.208444  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushMRSOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:07.242111  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushMRSOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.033s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1357582,"cfile_init":1,"dirs.queue_time_us":40,"dirs.run_cpu_time_us":266,"dirs.run_wall_time_us":1525,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1685,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:17:07.242781  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling LogGCOp(b852673544c54f23bf98cc1270a88646): free 128867727 bytes of WAL
I20260812 06:17:07.243013  8601 log_reader.cc:385] T b852673544c54f23bf98cc1270a88646: removed 13 log segments from log reader
I20260812 06:17:07.243122  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000028 (ops 135-138)
I20260812 06:17:07.243191  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000029 (ops 139-143)
I20260812 06:17:07.243247  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000030 (ops 144-148)
I20260812 06:17:07.243289  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000031 (ops 149-152)
I20260812 06:17:07.243328  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000032 (ops 153-157)
I20260812 06:17:07.243366  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000033 (ops 158-162)
I20260812 06:17:07.243403  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000034 (ops 163-166)
I20260812 06:17:07.243441  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000035 (ops 167-171)
I20260812 06:17:07.243479  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000036 (ops 172-176)
I20260812 06:17:07.243515  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000037 (ops 177-181)
I20260812 06:17:07.243551  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000038 (ops 182-186)
I20260812 06:17:07.243589  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000039 (ops 187-191)
I20260812 06:17:07.243628  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000040 (ops 192-196)
I20260812 06:17:07.276960  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: LogGCOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.034s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:07.277494  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=3.181125
I20260812 06:17:07.300846  8268 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.995s	user 1.841s	sys 0.204s
I20260812 06:17:07.302623  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.025s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6976,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:07.303184  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling LogGCOp(b852673544c54f23bf98cc1270a88646): free 12017949 bytes of WAL
I20260812 06:17:07.303452  8601 log_reader.cc:385] T b852673544c54f23bf98cc1270a88646: removed 1 log segments from log reader
I20260812 06:17:07.303516  8601 log.cc:1079] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: Deleting log segment in path: /tmp/dist-test-tasklQOFM4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416744403-8268-0/minicluster-data/ts-0-root/wals/b852673544c54f23bf98cc1270a88646/wal-000000041 (ops 197-201)
I20260812 06:17:07.306531  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: LogGCOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.003s	user 0.001s	sys 0.002s Metrics: {}
I20260812 06:17:07.306917  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling UndoDeltaBlockGCOp(b852673544c54f23bf98cc1270a88646): 506 bytes on disk
I20260812 06:17:07.307436  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: UndoDeltaBlockGCOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:17:07.308032  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646): perf score=2.188937
I20260812 06:17:07.321518  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: FlushDeltaMemStoresOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5331,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:07.322032  8672 maintenance_manager.cc:419] P 0138e7adb6b14ba19635a77ad0aee470: Scheduling MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646): perf score=1.000000
I20260812 06:17:07.398025  8268 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.097s	user 0.003s	sys 0.000s
I20260812 06:17:07.398582  8268 tablet_server.cc:179] TabletServer@127.8.19.1:0 shutting down...
I20260812 06:17:07.490492  8601 maintenance_manager.cc:643] P 0138e7adb6b14ba19635a77ad0aee470: MajorDeltaCompactionOp(b852673544c54f23bf98cc1270a88646) complete. Timing: real 0.168s	user 0.107s	sys 0.060s Metrics: {"cfile_cache_hit":259,"cfile_cache_hit_bytes":10507178,"cfile_cache_miss":475,"cfile_cache_miss_bytes":22472561,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":630,"lbm_read_time_us":9424,"lbm_reads_lt_1ms":507,"lbm_write_time_us":33354,"lbm_writes_lt_1ms":743,"mutex_wait_us":108,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":43776,"thread_start_us":66,"threads_started":1,"update_count":3500}
I20260812 06:17:07.491446  8268 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:07.491848  8268 tablet_replica.cc:333] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470: stopping tablet replica
I20260812 06:17:07.492056  8268 raft_consensus.cc:2243] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:07.492280  8268 raft_consensus.cc:2272] T b852673544c54f23bf98cc1270a88646 P 0138e7adb6b14ba19635a77ad0aee470 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:07.495925  8268 tablet_server.cc:196] TabletServer@127.8.19.1:0 shutdown complete.
I20260812 06:17:07.548368  8268 master.cc:562] Master@127.8.19.62:36305 shutting down...
I20260812 06:17:07.552191  8268 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:07.552423  8268 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:07.552513  8268 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3d27ac348d864439af651d356e60338a: stopping tablet replica
I20260812 06:17:07.565152  8268 master.cc:584] Master@127.8.19.62:36305 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5546 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10895 ms total)

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