[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:38.022560  2553 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.126.126:34289
I20260812 06:19:38.023609  2553 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:38.024223  2553 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:38.031293  2563 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:38.031303  2561 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:38.031605  2553 server_base.cc:1061] running on GCE node
W20260812 06:19:38.031607  2559 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:38.032231  2553 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:38.032348  2553 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:38.032399  2553 hybrid_clock.cc:648] HybridClock initialized: now 1786515578032396 us; error 0 us; skew 500 ppm
I20260812 06:19:38.034384  2553 webserver.cc:533] Webserver started at http://127.2.126.126:38541/ using document root <none> and password file <none>
I20260812 06:19:38.034987  2553 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:38.035079  2553 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:38.035368  2553 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:38.037098  2553 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/master-0-root/instance:
uuid: "0e06b188192f4cd984ca9cce87dfdeb8"
format_stamp: "Formatted at 2026-08-12 06:19:38 on dist-test-slave-9gcw"
I20260812 06:19:38.040915  2553 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:38.043148  2569 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:38.044265  2553 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:38.044406  2553 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/master-0-root
uuid: "0e06b188192f4cd984ca9cce87dfdeb8"
format_stamp: "Formatted at 2026-08-12 06:19:38 on dist-test-slave-9gcw"
I20260812 06:19:38.044515  2553 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:38.076884  2553 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:38.077622  2553 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:38.077826  2553 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:38.085649  2553 rpc_server.cc:307] RPC server started. Bound to: 127.2.126.126:34289
I20260812 06:19:38.085654  2626 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.126.126:34289 every 8 connection(s)
I20260812 06:19:38.088006  2627 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:38.093500  2627 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8: Bootstrap starting.
I20260812 06:19:38.095916  2627 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:38.096843  2627 log.cc:826] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:38.098619  2627 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8: No bootstrap required, opened a new log
I20260812 06:19:38.101388  2627 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0e06b188192f4cd984ca9cce87dfdeb8" member_type: VOTER }
I20260812 06:19:38.101550  2627 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:38.101686  2627 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0e06b188192f4cd984ca9cce87dfdeb8, State: Initialized, Role: FOLLOWER
I20260812 06:19:38.102366  2627 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [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: "0e06b188192f4cd984ca9cce87dfdeb8" member_type: VOTER }
I20260812 06:19:38.102541  2627 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:38.102613  2627 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:38.102763  2627 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:38.103578  2627 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0e06b188192f4cd984ca9cce87dfdeb8" member_type: VOTER }
I20260812 06:19:38.104045  2627 leader_election.cc:304] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [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: 0e06b188192f4cd984ca9cce87dfdeb8; no voters: 
I20260812 06:19:38.104429  2627 leader_election.cc:290] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:38.104554  2631 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:38.104852  2631 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [term 1 LEADER]: Becoming Leader. State: Replica: 0e06b188192f4cd984ca9cce87dfdeb8, State: Running, Role: LEADER
I20260812 06:19:38.105363  2631 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [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: "0e06b188192f4cd984ca9cce87dfdeb8" member_type: VOTER }
I20260812 06:19:38.105536  2627 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:38.107285  2634 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0e06b188192f4cd984ca9cce87dfdeb8. Latest consensus state: current_term: 1 leader_uuid: "0e06b188192f4cd984ca9cce87dfdeb8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0e06b188192f4cd984ca9cce87dfdeb8" member_type: VOTER } }
I20260812 06:19:38.107326  2633 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0e06b188192f4cd984ca9cce87dfdeb8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0e06b188192f4cd984ca9cce87dfdeb8" member_type: VOTER } }
I20260812 06:19:38.107412  2634 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:38.107420  2633 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:38.107767  2646 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:38.108093  2553 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:38.110172  2646 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:38.114655  2646 catalog_manager.cc:1383] Generated new cluster ID: 4c402a2ed0dc4078ae7cb5dff728d8c5
I20260812 06:19:38.114724  2646 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:38.144357  2646 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:38.145653  2646 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:38.158008  2646 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8: Generated new TSK 0
I20260812 06:19:38.158829  2646 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:38.173791  2553 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:38.177084  2658 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:38.177047  2655 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:38.177048  2654 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:38.177379  2553 server_base.cc:1061] running on GCE node
I20260812 06:19:38.177634  2553 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:38.177680  2553 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:38.177696  2553 hybrid_clock.cc:648] HybridClock initialized: now 1786515578177697 us; error 0 us; skew 500 ppm
I20260812 06:19:38.178598  2553 webserver.cc:533] Webserver started at http://127.2.126.65:42859/ using document root <none> and password file <none>
I20260812 06:19:38.178790  2553 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:38.178879  2553 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:38.178962  2553 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:38.179382  2553 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/instance:
uuid: "99e8e916028a45bdae638d348453c582"
format_stamp: "Formatted at 2026-08-12 06:19:38 on dist-test-slave-9gcw"
I20260812 06:19:38.180969  2553 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:38.182049  2665 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:38.182318  2553 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:38.182381  2553 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root
uuid: "99e8e916028a45bdae638d348453c582"
format_stamp: "Formatted at 2026-08-12 06:19:38 on dist-test-slave-9gcw"
I20260812 06:19:38.182471  2553 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:38.197010  2553 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:38.197530  2553 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:38.198048  2553 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:38.198948  2553 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:38.199000  2553 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:38.199074  2553 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:38.199115  2553 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:38.206383  2553 rpc_server.cc:307] RPC server started. Bound to: 127.2.126.65:42387
I20260812 06:19:38.206453  2736 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.126.65:42387 every 8 connection(s)
I20260812 06:19:38.223832  2737 heartbeater.cc:344] Connected to a master server at 127.2.126.126:34289
I20260812 06:19:38.224115  2737 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:38.224632  2737 heartbeater.cc:507] Master 127.2.126.126:34289 requested a full tablet report, sending...
I20260812 06:19:38.226238  2588 ts_manager.cc:194] Registered new tserver with Master: 99e8e916028a45bdae638d348453c582 (127.2.126.65:42387)
I20260812 06:19:38.226353  2553 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.019203822s
I20260812 06:19:38.227813  2588 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39158
I20260812 06:19:38.236234  2588 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39174:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:38.250823  2697 tablet_service.cc:1511] Processing CreateTablet for tablet ca5f3bca7eb848d1a04b95e5b12cbf1c (DEFAULT_TABLE table=heavy-update-compaction-test [id=f691bab65e36407a88394b34d9d488bc]), partition=
I20260812 06:19:38.251324  2697 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ca5f3bca7eb848d1a04b95e5b12cbf1c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:38.253643  2753 tablet_bootstrap.cc:492] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Bootstrap starting.
I20260812 06:19:38.254820  2753 tablet_bootstrap.cc:654] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:38.256392  2753 tablet_bootstrap.cc:492] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: No bootstrap required, opened a new log
I20260812 06:19:38.256517  2753 ts_tablet_manager.cc:1403] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:38.257023  2753 raft_consensus.cc:359] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "99e8e916028a45bdae638d348453c582" member_type: VOTER last_known_addr { host: "127.2.126.65" port: 42387 } }
I20260812 06:19:38.257155  2753 raft_consensus.cc:385] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:38.257244  2753 raft_consensus.cc:740] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 99e8e916028a45bdae638d348453c582, State: Initialized, Role: FOLLOWER
I20260812 06:19:38.257392  2753 consensus_queue.cc:260] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582 [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: "99e8e916028a45bdae638d348453c582" member_type: VOTER last_known_addr { host: "127.2.126.65" port: 42387 } }
I20260812 06:19:38.257509  2753 raft_consensus.cc:399] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:38.257560  2753 raft_consensus.cc:493] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:38.257612  2753 raft_consensus.cc:3060] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:38.258412  2753 raft_consensus.cc:515] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "99e8e916028a45bdae638d348453c582" member_type: VOTER last_known_addr { host: "127.2.126.65" port: 42387 } }
I20260812 06:19:38.258585  2753 leader_election.cc:304] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582 [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: 99e8e916028a45bdae638d348453c582; no voters: 
I20260812 06:19:38.258843  2753 leader_election.cc:290] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:38.259183  2755 raft_consensus.cc:2804] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:38.259449  2755 raft_consensus.cc:697] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582 [term 1 LEADER]: Becoming Leader. State: Replica: 99e8e916028a45bdae638d348453c582, State: Running, Role: LEADER
I20260812 06:19:38.259526  2753 ts_tablet_manager.cc:1434] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:38.259701  2755 consensus_queue.cc:237] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582 [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: "99e8e916028a45bdae638d348453c582" member_type: VOTER last_known_addr { host: "127.2.126.65" port: 42387 } }
I20260812 06:19:38.259860  2737 heartbeater.cc:499] Master 127.2.126.126:34289 was elected leader, sending a full tablet report...
I20260812 06:19:38.262614  2588 catalog_manager.cc:5719] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582 reported cstate change: term changed from 0 to 1, leader changed from <none> to 99e8e916028a45bdae638d348453c582 (127.2.126.65). New cstate: current_term: 1 leader_uuid: "99e8e916028a45bdae638d348453c582" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "99e8e916028a45bdae638d348453c582" member_type: VOTER last_known_addr { host: "127.2.126.65" port: 42387 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:38.336083  2553 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.064s	user 0.022s	sys 0.009s
I20260812 06:19:38.457734  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushMRSOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=15.086190
I20260812 06:19:38.614704  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushMRSOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.156s	user 0.106s	sys 0.044s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":10236,"delete_count":0,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1082,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38152,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":180,"threads_started":1,"update_count":1500}
I20260812 06:19:38.615931  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling LogGCOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): free 11976772 bytes of WAL
I20260812 06:19:38.616269  2670 log_reader.cc:385] T ca5f3bca7eb848d1a04b95e5b12cbf1c: removed 1 log segments from log reader
I20260812 06:19:38.616340  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000001 (ops 1-6)
I20260812 06:19:38.619590  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: LogGCOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:38.619966  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling UndoDeltaBlockGCOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): 12308960 bytes on disk
I20260812 06:19:38.620630  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: UndoDeltaBlockGCOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:19:38.621094  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:38.640625  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.019s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5783,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.641136  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:38.655943  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5673,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.656422  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:38.829981  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.173s	user 0.131s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733843,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":894,"lbm_read_time_us":10574,"lbm_reads_lt_1ms":569,"lbm_write_time_us":31736,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":340,"threads_started":5,"update_count":2500}
I20260812 06:19:38.830591  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=10.126437
I20260812 06:19:38.866791  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.036s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14958,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.867367  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:38.880847  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4889,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.881565  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:39.014554  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.133s	user 0.087s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":213,"lbm_read_time_us":9521,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27390,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":26496,"update_count":2000}
I20260812 06:19:39.015041  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=10.126437
I20260812 06:19:39.065475  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.050s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17084,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:39.065994  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:39.077339  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4055,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.077939  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:39.196000  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.118s	user 0.102s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":263,"lbm_read_time_us":8264,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21853,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2000}
I20260812 06:19:39.196640  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=10.126437
I20260812 06:19:39.241212  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.044s	user 0.022s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14697,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:39.241734  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:39.252913  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4326,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.253597  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:39.401333  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.148s	user 0.101s	sys 0.046s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":711,"lbm_read_time_us":10484,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26907,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2000}
I20260812 06:19:39.402067  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=10.126437
I20260812 06:19:39.447966  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.046s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16953,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:39.448475  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:39.459411  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.459996  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:39.586097  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.126s	user 0.110s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1057,"lbm_read_time_us":8331,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25176,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2000}
I20260812 06:19:39.586897  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=10.126437
I20260812 06:19:39.632174  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.045s	user 0.023s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18802,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:39.632629  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:39.645422  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.013s	user 0.000s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4579,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.645923  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:39.764259  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.118s	user 0.099s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":362,"lbm_read_time_us":7402,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23605,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:39.764815  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=10.126437
I20260812 06:19:39.802548  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.038s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16630,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:39.803122  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:39.819212  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.016s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5891,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.819902  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushMRSOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:39.847796  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushMRSOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.028s	user 0.023s	sys 0.003s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":270,"dirs.run_wall_time_us":1568,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1564,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:39.848582  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling LogGCOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): free 121006369 bytes of WAL
I20260812 06:19:39.848843  2670 log_reader.cc:385] T ca5f3bca7eb848d1a04b95e5b12cbf1c: removed 12 log segments from log reader
I20260812 06:19:39.848891  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000002 (ops 7-11)
I20260812 06:19:39.848922  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000003 (ops 12-16)
I20260812 06:19:39.848989  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000004 (ops 17-20)
I20260812 06:19:39.849030  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000005 (ops 21-25)
I20260812 06:19:39.849071  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000006 (ops 26-30)
I20260812 06:19:39.849134  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000007 (ops 31-35)
I20260812 06:19:39.849207  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000008 (ops 36-40)
I20260812 06:19:39.849241  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000009 (ops 41-45)
I20260812 06:19:39.849277  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000010 (ops 46-50)
I20260812 06:19:39.849313  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000011 (ops 51-55)
I20260812 06:19:39.849370  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000012 (ops 56-60)
I20260812 06:19:39.849407  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000013 (ops 61-65)
I20260812 06:19:39.876096  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: LogGCOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:39.876605  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling UndoDeltaBlockGCOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): 462 bytes on disk
I20260812 06:19:39.877197  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: UndoDeltaBlockGCOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) 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:19:39.877694  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=3.181125
I20260812 06:19:39.889734  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4438,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:39.890206  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:39.899910  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3519,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.900408  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:40.072965  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.172s	user 0.128s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836359,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":479,"lbm_read_time_us":11606,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32598,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5888,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:19:40.073658  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=14.095187
I20260812 06:19:40.126151  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.052s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20807,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.126638  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:40.139001  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4564,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.139708  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:40.309599  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.170s	user 0.129s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":216,"lbm_read_time_us":10069,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33697,"lbm_writes_lt_1ms":543,"mutex_wait_us":74,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:40.310360  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=14.095187
I20260812 06:19:40.362819  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.052s	user 0.034s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22678,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.363335  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:40.532809  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.169s	user 0.098s	sys 0.061s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631191,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":335,"lbm_read_time_us":11367,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27857,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2000}
I20260812 06:19:40.533516  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=14.095187
I20260812 06:19:40.597848  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.061s	user 0.030s	sys 0.029s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22545,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.598464  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:40.609654  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4265,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.610124  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:40.798756  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.188s	user 0.121s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":715,"lbm_read_time_us":12344,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35653,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:40.799441  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=11.118625
I20260812 06:19:40.846410  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.047s	user 0.031s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20271,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:19:40.847018  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:40.870898  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4360,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.871496  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:40.881551  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3783,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:40.882164  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:41.054694  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.172s	user 0.132s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":375,"lbm_read_time_us":13405,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28543,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":32128,"update_count":2500}
I20260812 06:19:41.055306  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=10.126437
I20260812 06:19:41.092931  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.037s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16298,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.093415  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:41.108243  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5399,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.108958  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:41.240969  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.132s	user 0.107s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":7315,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27147,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:19:41.241640  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=10.126437
I20260812 06:19:41.286303  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.044s	user 0.009s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14649,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.286769  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:41.297272  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3915,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.298091  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushMRSOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:41.327711  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushMRSOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":151,"dirs.run_wall_time_us":1527,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1833,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:41.328559  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling LogGCOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): free 120553433 bytes of WAL
I20260812 06:19:41.328832  2670 log_reader.cc:385] T ca5f3bca7eb848d1a04b95e5b12cbf1c: removed 12 log segments from log reader
I20260812 06:19:41.328893  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000014 (ops 66-70)
I20260812 06:19:41.328934  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000015 (ops 71-74)
I20260812 06:19:41.328970  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000016 (ops 75-79)
I20260812 06:19:41.328994  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000017 (ops 80-84)
I20260812 06:19:41.329020  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000018 (ops 85-88)
I20260812 06:19:41.329051  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000019 (ops 89-93)
I20260812 06:19:41.329077  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000020 (ops 94-98)
I20260812 06:19:41.329111  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000021 (ops 99-103)
I20260812 06:19:41.329181  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000022 (ops 104-108)
I20260812 06:19:41.329216  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000023 (ops 109-113)
I20260812 06:19:41.329237  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000024 (ops 114-118)
I20260812 06:19:41.329258  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000025 (ops 119-123)
I20260812 06:19:41.357981  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: LogGCOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:41.358520  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:41.380869  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.022s	user 0.010s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5418,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.381434  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling UndoDeltaBlockGCOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): 462 bytes on disk
I20260812 06:19:41.381851  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: UndoDeltaBlockGCOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:41.382400  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:41.392984  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4089,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.393553  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:41.566284  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.173s	user 0.124s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836372,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":801,"lbm_read_time_us":12646,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34812,"lbm_writes_lt_1ms":643,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6528,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:19:41.568634  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=14.095187
I20260812 06:19:41.619993  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.051s	user 0.017s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20945,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.620577  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:41.636605  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5840,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.637523  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:41.785290  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.147s	user 0.112s	sys 0.034s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":956,"lbm_read_time_us":9834,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30111,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2500}
I20260812 06:19:41.785820  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=10.126437
I20260812 06:19:41.816120  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.030s	user 0.014s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13256,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.816596  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:41.831112  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.014s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4283,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.831619  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:41.973605  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.142s	user 0.103s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":404,"lbm_read_time_us":9496,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24904,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:41.974148  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=10.126437
I20260812 06:19:42.017730  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.043s	user 0.022s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16320,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.018296  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:42.031781  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4551,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.032405  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:42.183753  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.151s	user 0.125s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":647,"lbm_read_time_us":9723,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27236,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":71424,"update_count":2000}
I20260812 06:19:42.184541  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=14.095187
I20260812 06:19:42.237918  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.053s	user 0.029s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":26981,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.238478  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:42.252516  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.014s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5193,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.253218  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:42.425268  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.172s	user 0.149s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":599,"lbm_read_time_us":12583,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29354,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:42.426222  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=14.095187
I20260812 06:19:42.474443  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.048s	user 0.022s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17953,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.475069  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:42.493592  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.018s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5468,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.494051  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:42.679509  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.185s	user 0.119s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":853,"lbm_read_time_us":11010,"lbm_reads_lt_1ms":568,"lbm_write_time_us":33026,"lbm_writes_lt_1ms":543,"mutex_wait_us":292,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:19:42.680294  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=14.095187
I20260812 06:19:42.732831  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.052s	user 0.022s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20625,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.733378  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:42.752134  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.019s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3987,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.752949  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushMRSOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:42.788498  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushMRSOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.035s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1703,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2240,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:42.789331  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling LogGCOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): free 124710540 bytes of WAL
I20260812 06:19:42.789572  2670 log_reader.cc:385] T ca5f3bca7eb848d1a04b95e5b12cbf1c: removed 12 log segments from log reader
I20260812 06:19:42.789621  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000026 (ops 124-128)
I20260812 06:19:42.789654  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000027 (ops 129-133)
I20260812 06:19:42.789728  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000028 (ops 134-138)
I20260812 06:19:42.789777  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000029 (ops 139-143)
I20260812 06:19:42.789826  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000030 (ops 144-148)
I20260812 06:19:42.789901  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000031 (ops 149-153)
I20260812 06:19:42.789968  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000032 (ops 154-158)
I20260812 06:19:42.790016  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000033 (ops 159-163)
I20260812 06:19:42.790062  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000034 (ops 164-168)
I20260812 06:19:42.790117  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000035 (ops 169-173)
I20260812 06:19:42.790166  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000036 (ops 174-178)
I20260812 06:19:42.790213  2670 log.cc:1079] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/ca5f3bca7eb848d1a04b95e5b12cbf1c/wal-000000037 (ops 179-183)
I20260812 06:19:42.816032  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: LogGCOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:42.816533  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:42.835201  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.018s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5740,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.835644  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:42.845954  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.010s	user 0.004s	sys 0.005s 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:19:42.846376  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:43.072384  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.226s	user 0.147s	sys 0.077s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938786,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":519,"lbm_read_time_us":14382,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38910,"lbm_writes_lt_1ms":743,"mutex_wait_us":66,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":112,"threads_started":1,"update_count":3500}
I20260812 06:19:43.075858  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling UndoDeltaBlockGCOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): 473 bytes on disk
I20260812 06:19:43.076613  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: UndoDeltaBlockGCOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":106,"lbm_reads_lt_1ms":4}
I20260812 06:19:43.077371  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=14.095187
I20260812 06:19:43.138289  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.061s	user 0.028s	sys 0.025s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":23501,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.138810  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=2.188937
I20260812 06:19:43.150738  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: FlushDeltaMemStoresOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3946,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.151347  2740 maintenance_manager.cc:419] P 99e8e916028a45bdae638d348453c582: Scheduling MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c): perf score=1.000000
I20260812 06:19:43.238399  2553 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.902s	user 1.822s	sys 0.104s
I20260812 06:19:43.306185  2553 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.067s	user 0.003s	sys 0.000s
I20260812 06:19:43.306934  2553 tablet_server.cc:179] TabletServer@127.2.126.65:0 shutting down...
I20260812 06:19:43.315037  2670 maintenance_manager.cc:643] P 99e8e916028a45bdae638d348453c582: MajorDeltaCompactionOp(ca5f3bca7eb848d1a04b95e5b12cbf1c) complete. Timing: real 0.163s	user 0.115s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733721,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1109,"lbm_read_time_us":12523,"lbm_reads_lt_1ms":568,"lbm_write_time_us":27743,"lbm_writes_lt_1ms":543,"mutex_wait_us":311,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17664,"update_count":2500}
I20260812 06:19:43.315706  2553 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:43.316118  2553 tablet_replica.cc:333] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582: stopping tablet replica
I20260812 06:19:43.316349  2553 raft_consensus.cc:2243] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:43.316578  2553 raft_consensus.cc:2272] T ca5f3bca7eb848d1a04b95e5b12cbf1c P 99e8e916028a45bdae638d348453c582 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:43.332526  2553 tablet_server.cc:196] TabletServer@127.2.126.65:0 shutdown complete.
I20260812 06:19:43.363073  2553 master.cc:562] Master@127.2.126.126:34289 shutting down...
I20260812 06:19:43.367251  2553 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:43.367429  2553 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:43.367483  2553 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0e06b188192f4cd984ca9cce87dfdeb8: stopping tablet replica
I20260812 06:19:43.379969  2553 master.cc:584] Master@127.2.126.126:34289 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5446 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:43.479396  2553 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.126.126:41483
I20260812 06:19:43.479851  2553 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:43.482499  2776 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:43.482547  2553 server_base.cc:1061] running on GCE node
W20260812 06:19:43.482548  2778 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:43.482818  2775 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:43.483139  2553 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:43.483196  2553 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:43.483218  2553 hybrid_clock.cc:648] HybridClock initialized: now 1786515583483218 us; error 0 us; skew 500 ppm
I20260812 06:19:43.484294  2553 webserver.cc:533] Webserver started at http://127.2.126.126:34169/ using document root <none> and password file <none>
I20260812 06:19:43.484506  2553 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:43.484572  2553 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:43.484694  2553 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:43.485299  2553 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/master-0-root/instance:
uuid: "7df5a4e198c2400a8b7938c34f26e869"
format_stamp: "Formatted at 2026-08-12 06:19:43 on dist-test-slave-9gcw"
I20260812 06:19:43.487114  2553 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:43.488021  2784 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:43.488294  2553 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:43.488353  2553 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/master-0-root
uuid: "7df5a4e198c2400a8b7938c34f26e869"
format_stamp: "Formatted at 2026-08-12 06:19:43 on dist-test-slave-9gcw"
I20260812 06:19:43.488445  2553 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:43.505944  2553 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:43.506381  2553 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:43.510419  2553 rpc_server.cc:307] RPC server started. Bound to: 127.2.126.126:41483
I20260812 06:19:43.512144  2839 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.126.126:41483 every 8 connection(s)
I20260812 06:19:43.512558  2842 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:43.515080  2842 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869: Bootstrap starting.
I20260812 06:19:43.515900  2842 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:43.516978  2842 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869: No bootstrap required, opened a new log
I20260812 06:19:43.517473  2842 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7df5a4e198c2400a8b7938c34f26e869" member_type: VOTER }
I20260812 06:19:43.517585  2842 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:43.517632  2842 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7df5a4e198c2400a8b7938c34f26e869, State: Initialized, Role: FOLLOWER
I20260812 06:19:43.517799  2842 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [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: "7df5a4e198c2400a8b7938c34f26e869" member_type: VOTER }
I20260812 06:19:43.517891  2842 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:43.517935  2842 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:43.517990  2842 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:43.518657  2842 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7df5a4e198c2400a8b7938c34f26e869" member_type: VOTER }
I20260812 06:19:43.518806  2842 leader_election.cc:304] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [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: 7df5a4e198c2400a8b7938c34f26e869; no voters: 
I20260812 06:19:43.519007  2842 leader_election.cc:290] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:43.519142  2845 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:43.519371  2845 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [term 1 LEADER]: Becoming Leader. State: Replica: 7df5a4e198c2400a8b7938c34f26e869, State: Running, Role: LEADER
I20260812 06:19:43.519471  2842 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:43.519553  2845 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [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: "7df5a4e198c2400a8b7938c34f26e869" member_type: VOTER }
I20260812 06:19:43.520010  2846 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7df5a4e198c2400a8b7938c34f26e869" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7df5a4e198c2400a8b7938c34f26e869" member_type: VOTER } }
I20260812 06:19:43.520131  2846 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:43.520025  2847 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7df5a4e198c2400a8b7938c34f26e869. Latest consensus state: current_term: 1 leader_uuid: "7df5a4e198c2400a8b7938c34f26e869" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7df5a4e198c2400a8b7938c34f26e869" member_type: VOTER } }
I20260812 06:19:43.520355  2847 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:43.520807  2852 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:43.521692  2852 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:43.521863  2553 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:43.523497  2852 catalog_manager.cc:1383] Generated new cluster ID: bd4eb50a08a643ea91d194d773fa298d
I20260812 06:19:43.523559  2852 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:43.539211  2852 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:43.539822  2852 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:43.545791  2852 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869: Generated new TSK 0
I20260812 06:19:43.545981  2852 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:43.554303  2553 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:43.556890  2868 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:43.557006  2871 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:43.556882  2553 server_base.cc:1061] running on GCE node
W20260812 06:19:43.556936  2869 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:43.557410  2553 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:43.557469  2553 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:43.557508  2553 hybrid_clock.cc:648] HybridClock initialized: now 1786515583557507 us; error 0 us; skew 500 ppm
I20260812 06:19:43.558485  2553 webserver.cc:533] Webserver started at http://127.2.126.65:41233/ using document root <none> and password file <none>
I20260812 06:19:43.558684  2553 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:43.558760  2553 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:43.558842  2553 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:43.559266  2553 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/instance:
uuid: "eacde87f230c4ab48bb5e1e907976c72"
format_stamp: "Formatted at 2026-08-12 06:19:43 on dist-test-slave-9gcw"
I20260812 06:19:43.560778  2553 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:43.561825  2876 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:43.562081  2553 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:43.562167  2553 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root
uuid: "eacde87f230c4ab48bb5e1e907976c72"
format_stamp: "Formatted at 2026-08-12 06:19:43 on dist-test-slave-9gcw"
I20260812 06:19:43.562250  2553 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:43.580956  2553 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:43.581437  2553 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:43.581780  2553 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:43.582312  2553 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:43.582386  2553 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:43.582446  2553 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:43.582496  2553 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:43.587095  2553 rpc_server.cc:307] RPC server started. Bound to: 127.2.126.65:33247
I20260812 06:19:43.588721  2947 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.126.65:33247 every 8 connection(s)
I20260812 06:19:43.596388  2948 heartbeater.cc:344] Connected to a master server at 127.2.126.126:41483
I20260812 06:19:43.596524  2948 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:43.596750  2948 heartbeater.cc:507] Master 127.2.126.126:41483 requested a full tablet report, sending...
I20260812 06:19:43.597472  2802 ts_manager.cc:194] Registered new tserver with Master: eacde87f230c4ab48bb5e1e907976c72 (127.2.126.65:33247)
I20260812 06:19:43.598194  2553 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010124335s
I20260812 06:19:43.598218  2802 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56916
I20260812 06:19:43.605453  2802 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56924:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:43.614375  2909 tablet_service.cc:1511] Processing CreateTablet for tablet 96acf79e188f4337b5e0c4d468a3b6aa (DEFAULT_TABLE table=heavy-update-compaction-test [id=835c0dc19d114861817fa63e2e01e5e7]), partition=
I20260812 06:19:43.614632  2909 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 96acf79e188f4337b5e0c4d468a3b6aa. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:43.616524  2961 tablet_bootstrap.cc:492] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Bootstrap starting.
I20260812 06:19:43.617460  2961 tablet_bootstrap.cc:654] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:43.618487  2961 tablet_bootstrap.cc:492] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: No bootstrap required, opened a new log
I20260812 06:19:43.618561  2961 ts_tablet_manager.cc:1403] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:43.618945  2961 raft_consensus.cc:359] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "eacde87f230c4ab48bb5e1e907976c72" member_type: VOTER last_known_addr { host: "127.2.126.65" port: 33247 } }
I20260812 06:19:43.619031  2961 raft_consensus.cc:385] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:43.619053  2961 raft_consensus.cc:740] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: eacde87f230c4ab48bb5e1e907976c72, State: Initialized, Role: FOLLOWER
I20260812 06:19:43.619196  2961 consensus_queue.cc:260] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72 [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: "eacde87f230c4ab48bb5e1e907976c72" member_type: VOTER last_known_addr { host: "127.2.126.65" port: 33247 } }
I20260812 06:19:43.619282  2961 raft_consensus.cc:399] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:43.619306  2961 raft_consensus.cc:493] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:43.619342  2961 raft_consensus.cc:3060] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:43.620200  2961 raft_consensus.cc:515] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "eacde87f230c4ab48bb5e1e907976c72" member_type: VOTER last_known_addr { host: "127.2.126.65" port: 33247 } }
I20260812 06:19:43.620319  2961 leader_election.cc:304] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72 [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: eacde87f230c4ab48bb5e1e907976c72; no voters: 
I20260812 06:19:43.620515  2961 leader_election.cc:290] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:43.620657  2963 raft_consensus.cc:2804] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:43.620918  2961 ts_tablet_manager.cc:1434] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:43.620949  2948 heartbeater.cc:499] Master 127.2.126.126:41483 was elected leader, sending a full tablet report...
I20260812 06:19:43.620940  2963 raft_consensus.cc:697] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72 [term 1 LEADER]: Becoming Leader. State: Replica: eacde87f230c4ab48bb5e1e907976c72, State: Running, Role: LEADER
I20260812 06:19:43.621384  2963 consensus_queue.cc:237] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72 [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: "eacde87f230c4ab48bb5e1e907976c72" member_type: VOTER last_known_addr { host: "127.2.126.65" port: 33247 } }
I20260812 06:19:43.622735  2802 catalog_manager.cc:5719] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72 reported cstate change: term changed from 0 to 1, leader changed from <none> to eacde87f230c4ab48bb5e1e907976c72 (127.2.126.65). New cstate: current_term: 1 leader_uuid: "eacde87f230c4ab48bb5e1e907976c72" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "eacde87f230c4ab48bb5e1e907976c72" member_type: VOTER last_known_addr { host: "127.2.126.65" port: 33247 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:43.682865  2553 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.015s	sys 0.008s
I20260812 06:19:43.839272  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushMRSOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=19.054940
I20260812 06:19:44.005699  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushMRSOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.166s	user 0.114s	sys 0.052s Metrics: {"bytes_written":14276637,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1000,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44770,"lbm_writes_lt_1ms":805,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":896,"update_count":1740}
I20260812 06:19:44.006354  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling LogGCOp(96acf79e188f4337b5e0c4d468a3b6aa): free 20743880 bytes of WAL
I20260812 06:19:44.006601  2883 log_reader.cc:385] T 96acf79e188f4337b5e0c4d468a3b6aa: removed 2 log segments from log reader
I20260812 06:19:44.006661  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000001 (ops 1-6)
I20260812 06:19:44.006695  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000002 (ops 7-11)
I20260812 06:19:44.011425  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: LogGCOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:44.011910  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling UndoDeltaBlockGCOp(96acf79e188f4337b5e0c4d468a3b6aa): 16411393 bytes on disk
I20260812 06:19:44.012346  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: UndoDeltaBlockGCOp(96acf79e188f4337b5e0c4d468a3b6aa) 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:19:44.012737  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=4.173312
I20260812 06:19:44.029800  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":6071826,"delete_count":0,"lbm_write_time_us":6851,"lbm_writes_lt_1ms":151,"reinsert_count":0,"update_count":740}
I20260812 06:19:44.030289  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:44.219732  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.189s	user 0.106s	sys 0.072s Metrics: {"cfile_cache_miss":528,"cfile_cache_miss_bytes":24610585,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":997,"lbm_read_time_us":14363,"lbm_reads_lt_1ms":560,"lbm_write_time_us":28654,"lbm_writes_lt_1ms":539,"mutex_wait_us":38,"peak_mem_usage":61911376,"reinsert_count":0,"spinlock_wait_cycles":4608,"thread_start_us":350,"threads_started":5,"update_count":2480}
I20260812 06:19:44.220434  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=15.087375
I20260812 06:19:44.285050  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.064s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16573996,"delete_count":0,"lbm_write_time_us":21789,"lbm_writes_lt_1ms":407,"reinsert_count":0,"update_count":2020}
I20260812 06:19:44.285599  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:44.298233  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4266,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.298864  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:44.480579  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.181s	user 0.128s	sys 0.052s Metrics: {"cfile_cache_miss":536,"cfile_cache_miss_bytes":24938783,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":247,"lbm_read_time_us":11389,"lbm_reads_lt_1ms":576,"lbm_write_time_us":35084,"lbm_writes_lt_1ms":547,"mutex_wait_us":42,"peak_mem_usage":63280040,"reinsert_count":0,"spinlock_wait_cycles":60032,"update_count":2520}
I20260812 06:19:44.481237  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=14.095187
I20260812 06:19:44.543342  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.062s	user 0.030s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20785,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.543990  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:44.562955  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.019s	user 0.014s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7358,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.563647  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:44.747888  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.184s	user 0.132s	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":572,"lbm_read_time_us":13126,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31966,"lbm_writes_lt_1ms":543,"mutex_wait_us":249,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:19:44.748523  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=14.095187
I20260812 06:19:44.808499  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.060s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17683,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:44.809073  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:44.827256  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.018s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6902,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.827834  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:45.017930  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.190s	user 0.120s	sys 0.068s 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":367,"lbm_read_time_us":13851,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32516,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:19:45.018548  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=11.118625
I20260812 06:19:45.061856  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.043s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18776,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:45.062645  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:45.083631  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.021s	user 0.008s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6682,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:45.084229  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:45.282281  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.198s	user 0.130s	sys 0.048s 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":1043,"lbm_read_time_us":11324,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28653,"lbm_writes_lt_1ms":443,"mutex_wait_us":295,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2000}
I20260812 06:19:45.283047  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=14.095187
I20260812 06:19:45.337411  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.054s	user 0.043s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24255,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:45.337975  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:45.371356  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.033s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7299,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.371980  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:45.385499  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4786,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.386096  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushMRSOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:45.421257  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushMRSOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.035s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":101,"dirs.run_cpu_time_us":306,"dirs.run_wall_time_us":1697,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1881,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:45.421945  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling LogGCOp(96acf79e188f4337b5e0c4d468a3b6aa): free 121006453 bytes of WAL
I20260812 06:19:45.422214  2883 log_reader.cc:385] T 96acf79e188f4337b5e0c4d468a3b6aa: removed 12 log segments from log reader
I20260812 06:19:45.422287  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000003 (ops 12-16)
I20260812 06:19:45.422356  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000004 (ops 17-21)
I20260812 06:19:45.422423  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000005 (ops 22-26)
I20260812 06:19:45.422475  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000006 (ops 27-31)
I20260812 06:19:45.422521  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000007 (ops 32-36)
I20260812 06:19:45.422569  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000008 (ops 37-41)
I20260812 06:19:45.422619  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000009 (ops 42-46)
I20260812 06:19:45.422667  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000010 (ops 47-50)
I20260812 06:19:45.422715  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000011 (ops 51-55)
I20260812 06:19:45.422761  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000012 (ops 56-60)
I20260812 06:19:45.422811  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000013 (ops 61-65)
I20260812 06:19:45.422845  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000014 (ops 66-70)
I20260812 06:19:45.452150  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: LogGCOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.030s	user 0.005s	sys 0.022s Metrics: {}
I20260812 06:19:45.452883  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling UndoDeltaBlockGCOp(96acf79e188f4337b5e0c4d468a3b6aa): 472 bytes on disk
I20260812 06:19:45.453501  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: UndoDeltaBlockGCOp(96acf79e188f4337b5e0c4d468a3b6aa) 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:19:45.454231  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=6.157687
I20260812 06:19:45.491096  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.037s	user 0.026s	sys 0.009s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":15871,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:45.491793  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:45.782117  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.290s	user 0.196s	sys 0.093s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082160,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1243,"lbm_read_time_us":22264,"lbm_reads_lt_1ms":866,"lbm_write_time_us":48953,"lbm_writes_lt_1ms":843,"mutex_wait_us":793,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":85,"threads_started":1,"update_count":4000}
I20260812 06:19:45.782814  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=18.063937
I20260812 06:19:45.866541  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.082s	user 0.038s	sys 0.031s Metrics: {"bytes_written":20635387,"delete_count":0,"lbm_write_time_us":30359,"lbm_writes_lt_1ms":506,"mutex_wait_us":326,"reinsert_count":0,"update_count":2515}
I20260812 06:19:45.867007  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=6.157687
I20260812 06:19:45.904667  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.037s	user 0.016s	sys 0.008s Metrics: {"bytes_written":8082009,"delete_count":0,"lbm_write_time_us":11147,"lbm_writes_lt_1ms":200,"reinsert_count":0,"update_count":985}
I20260812 06:19:45.905280  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:45.916139  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4065,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.916952  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:46.178213  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.261s	user 0.172s	sys 0.088s Metrics: {"cfile_cache_miss":833,"cfile_cache_miss_bytes":37082048,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":241,"lbm_read_time_us":18822,"lbm_reads_lt_1ms":873,"lbm_write_time_us":46130,"lbm_writes_lt_1ms":843,"mutex_wait_us":34,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":19456,"update_count":4000}
I20260812 06:19:46.179001  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=18.063937
I20260812 06:19:46.249353  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.070s	user 0.062s	sys 0.008s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":30872,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:46.250171  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:46.273084  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.023s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5507,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.273666  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:46.284037  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.010s	user 0.005s	sys 0.003s 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:19:46.284482  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:46.470067  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.185s	user 0.145s	sys 0.040s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979634,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":108,"lbm_read_time_us":13195,"lbm_reads_lt_1ms":773,"lbm_write_time_us":42202,"lbm_writes_lt_1ms":743,"mutex_wait_us":50,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":3500}
I20260812 06:19:46.470783  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=14.095187
I20260812 06:19:46.512710  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.042s	user 0.031s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18643,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:46.513224  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:46.524430  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4224,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.525220  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:46.699324  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.174s	user 0.149s	sys 0.013s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":158,"lbm_read_time_us":10272,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33642,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2500}
I20260812 06:19:46.700022  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=14.095187
I20260812 06:19:46.758574  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.058s	user 0.026s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19017,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:46.759354  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:46.769979  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3987,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.770428  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:46.939803  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.169s	user 0.117s	sys 0.046s 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":224,"lbm_read_time_us":12440,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28297,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:19:46.940946  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=12.110812
I20260812 06:19:46.976332  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.035s	user 0.012s	sys 0.020s Metrics: {"bytes_written":13784351,"delete_count":0,"lbm_write_time_us":14956,"lbm_writes_lt_1ms":339,"reinsert_count":0,"update_count":1680}
I20260812 06:19:46.977422  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.196750
I20260812 06:19:46.990959  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.013s	user 0.005s	sys 0.005s Metrics: {"bytes_written":2625754,"delete_count":0,"lbm_write_time_us":3496,"lbm_writes_lt_1ms":67,"reinsert_count":0,"update_count":320}
I20260812 06:19:46.991487  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushMRSOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:47.046181  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushMRSOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.054s	user 0.029s	sys 0.002s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1583,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2057,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:47.047055  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling LogGCOp(96acf79e188f4337b5e0c4d468a3b6aa): free 124257253 bytes of WAL
I20260812 06:19:47.047360  2883 log_reader.cc:385] T 96acf79e188f4337b5e0c4d468a3b6aa: removed 12 log segments from log reader
I20260812 06:19:47.047433  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000015 (ops 71-75)
I20260812 06:19:47.047489  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000016 (ops 76-80)
I20260812 06:19:47.047544  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000017 (ops 81-85)
I20260812 06:19:47.047586  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000018 (ops 86-90)
I20260812 06:19:47.047623  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000019 (ops 91-94)
I20260812 06:19:47.047660  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000020 (ops 95-99)
I20260812 06:19:47.047695  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000021 (ops 100-104)
I20260812 06:19:47.047735  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000022 (ops 105-109)
I20260812 06:19:47.047772  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000023 (ops 110-114)
I20260812 06:19:47.047808  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000024 (ops 115-119)
I20260812 06:19:47.047847  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000025 (ops 120-124)
I20260812 06:19:47.047885  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000026 (ops 125-129)
I20260812 06:19:47.074949  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: LogGCOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:47.075454  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=6.157687
I20260812 06:19:47.104583  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.029s	user 0.019s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12733,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:47.105130  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling LogGCOp(96acf79e188f4337b5e0c4d468a3b6aa): free 8767152 bytes of WAL
I20260812 06:19:47.105506  2883 log_reader.cc:385] T 96acf79e188f4337b5e0c4d468a3b6aa: removed 1 log segments from log reader
I20260812 06:19:47.105587  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000027 (ops 130-134)
I20260812 06:19:47.107764  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: LogGCOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:47.108127  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling UndoDeltaBlockGCOp(96acf79e188f4337b5e0c4d468a3b6aa): 493 bytes on disk
I20260812 06:19:47.108654  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: UndoDeltaBlockGCOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4}
I20260812 06:19:47.109272  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:47.127475  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.018s	user 0.002s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7046,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.128154  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:47.357851  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.229s	user 0.146s	sys 0.077s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979708,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":329,"lbm_read_time_us":14861,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42123,"lbm_writes_lt_1ms":743,"mutex_wait_us":304,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":72,"threads_started":1,"update_count":3500}
I20260812 06:19:47.358431  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=18.063937
I20260812 06:19:47.416249  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.058s	user 0.038s	sys 0.016s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":25894,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:47.416872  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:47.429458  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.012s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4855,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.430024  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:47.598866  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.169s	user 0.130s	sys 0.038s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":551,"lbm_read_time_us":12233,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34474,"lbm_writes_lt_1ms":643,"mutex_wait_us":258,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":3000}
I20260812 06:19:47.599696  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=14.095187
I20260812 06:19:47.658875  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.059s	user 0.028s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27360,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.659440  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:47.684172  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.025s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5510,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.684671  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:47.695056  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3932,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.695514  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:47.879585  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.184s	user 0.126s	sys 0.048s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":552,"lbm_read_time_us":11678,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37003,"lbm_writes_lt_1ms":643,"mutex_wait_us":74,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":3000}
I20260812 06:19:47.880242  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=14.095187
I20260812 06:19:47.932976  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.053s	user 0.036s	sys 0.003s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18843,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.933506  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:47.949563  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5943,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.950193  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:48.109741  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.159s	user 0.122s	sys 0.036s 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":346,"lbm_read_time_us":10008,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30521,"lbm_writes_lt_1ms":543,"mutex_wait_us":81,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":2500}
I20260812 06:19:48.110976  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=13.103000
I20260812 06:19:48.160838  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.050s	user 0.029s	sys 0.016s Metrics: {"bytes_written":14686886,"delete_count":0,"lbm_write_time_us":21856,"lbm_writes_lt_1ms":361,"reinsert_count":0,"update_count":1790}
I20260812 06:19:48.161521  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:48.173686  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.012s	user 0.008s	sys 0.000s Metrics: {"bytes_written":1723202,"delete_count":0,"lbm_write_time_us":2836,"lbm_writes_lt_1ms":45,"reinsert_count":0,"update_count":210}
I20260812 06:19:48.174300  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:48.334092  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.160s	user 0.123s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672217,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":288,"lbm_read_time_us":9504,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26302,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:48.334834  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=14.095187
I20260812 06:19:48.383921  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.049s	user 0.033s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19999,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.384423  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:48.403518  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.019s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4065,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.404276  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushMRSOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:48.435587  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushMRSOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.031s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":1666,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1796,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28,"spinlock_wait_cycles":896}
I20260812 06:19:48.436358  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling LogGCOp(96acf79e188f4337b5e0c4d468a3b6aa): free 111786449 bytes of WAL
I20260812 06:19:48.436630  2883 log_reader.cc:385] T 96acf79e188f4337b5e0c4d468a3b6aa: removed 11 log segments from log reader
I20260812 06:19:48.436694  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000028 (ops 135-138)
I20260812 06:19:48.436735  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000029 (ops 139-143)
I20260812 06:19:48.436774  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000030 (ops 144-148)
I20260812 06:19:48.436798  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000031 (ops 149-152)
I20260812 06:19:48.436834  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000032 (ops 153-157)
I20260812 06:19:48.436867  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000033 (ops 158-162)
I20260812 06:19:48.436897  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000034 (ops 163-167)
I20260812 06:19:48.436919  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000035 (ops 168-172)
I20260812 06:19:48.436941  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000036 (ops 173-177)
I20260812 06:19:48.436964  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000037 (ops 178-182)
I20260812 06:19:48.436990  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000038 (ops 183-187)
I20260812 06:19:48.463498  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: LogGCOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:48.464319  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=2.188937
I20260812 06:19:48.478672  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.014s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4927,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":500}
I20260812 06:19:48.479243  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling LogGCOp(96acf79e188f4337b5e0c4d468a3b6aa): free 12018004 bytes of WAL
I20260812 06:19:48.479481  2883 log_reader.cc:385] T 96acf79e188f4337b5e0c4d468a3b6aa: removed 1 log segments from log reader
I20260812 06:19:48.479588  2883 log.cc:1079] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: Deleting log segment in path: /tmp/dist-test-tasklH26gC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578011725-2553-0/minicluster-data/ts-0-root/wals/96acf79e188f4337b5e0c4d468a3b6aa/wal-000000039 (ops 188-192)
I20260812 06:19:48.481936  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: LogGCOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:48.482362  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=1.000000
I20260812 06:19:48.702669  2553 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.020s	user 1.887s	sys 0.167s
I20260812 06:19:48.705644  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: MajorDeltaCompactionOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.223s	user 0.157s	sys 0.053s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1220,"lbm_read_time_us":13896,"lbm_reads_lt_1ms":665,"lbm_write_time_us":38660,"lbm_writes_lt_1ms":643,"mutex_wait_us":479,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":107,"threads_started":1,"update_count":3000}
I20260812 06:19:48.706389  2949 maintenance_manager.cc:419] P eacde87f230c4ab48bb5e1e907976c72: Scheduling FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa): perf score=18.063937
I20260812 06:19:48.734845  2553 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.032s	user 0.003s	sys 0.004s
I20260812 06:19:48.735565  2553 tablet_server.cc:179] TabletServer@127.2.126.65:0 shutting down...
I20260812 06:19:48.778872  2883 maintenance_manager.cc:643] P eacde87f230c4ab48bb5e1e907976c72: FlushDeltaMemStoresOp(96acf79e188f4337b5e0c4d468a3b6aa) complete. Timing: real 0.072s	user 0.055s	sys 0.016s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":28667,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:48.779505  2553 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:48.779739  2553 tablet_replica.cc:333] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72: stopping tablet replica
I20260812 06:19:48.779909  2553 raft_consensus.cc:2243] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:48.780090  2553 raft_consensus.cc:2272] T 96acf79e188f4337b5e0c4d468a3b6aa P eacde87f230c4ab48bb5e1e907976c72 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:48.793977  2553 tablet_server.cc:196] TabletServer@127.2.126.65:0 shutdown complete.
I20260812 06:19:48.797274  2553 master.cc:562] Master@127.2.126.126:41483 shutting down...
I20260812 06:19:48.800701  2553 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:48.800873  2553 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:48.800925  2553 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7df5a4e198c2400a8b7938c34f26e869: stopping tablet replica
I20260812 06:19:48.813393  2553 master.cc:584] Master@127.2.126.126:41483 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5430 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10878 ms total)

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