[==========] 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:17:05.765888  2319 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.67.254:34539
I20260812 06:17:05.766943  2319 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:17:05.767551  2319 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:05.774216  2329 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:05.774247  2319 server_base.cc:1061] running on GCE node
W20260812 06:17:05.774435  2326 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:05.774603  2327 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:05.775367  2319 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:05.775532  2319 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:05.775593  2319 hybrid_clock.cc:648] HybridClock initialized: now 1786515425775590 us; error 0 us; skew 500 ppm
I20260812 06:17:05.777400  2319 webserver.cc:533] Webserver started at http://127.2.67.254:37859/ using document root <none> and password file <none>
I20260812 06:17:05.777966  2319 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:05.778051  2319 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:05.778291  2319 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:05.780021  2319 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/master-0-root/instance:
uuid: "c06cd7a7106546ebbc23770b26fbdcb0"
format_stamp: "Formatted at 2026-08-12 06:17:05 on dist-test-slave-7c35"
I20260812 06:17:05.783663  2319 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:17:05.785722  2335 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:05.786692  2319 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:05.786829  2319 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/master-0-root
uuid: "c06cd7a7106546ebbc23770b26fbdcb0"
format_stamp: "Formatted at 2026-08-12 06:17:05 on dist-test-slave-7c35"
I20260812 06:17:05.786990  2319 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:05.797489  2319 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:05.798075  2319 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:17:05.798243  2319 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:05.805966  2319 rpc_server.cc:307] RPC server started. Bound to: 127.2.67.254:34539
I20260812 06:17:05.805964  2406 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.67.254:34539 every 8 connection(s)
I20260812 06:17:05.808204  2407 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:05.813599  2407 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0: Bootstrap starting.
I20260812 06:17:05.815941  2407 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:05.816877  2407 log.cc:826] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:05.818492  2407 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0: No bootstrap required, opened a new log
I20260812 06:17:05.821219  2407 raft_consensus.cc:359] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c06cd7a7106546ebbc23770b26fbdcb0" member_type: VOTER }
I20260812 06:17:05.821373  2407 raft_consensus.cc:385] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:05.821456  2407 raft_consensus.cc:740] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c06cd7a7106546ebbc23770b26fbdcb0, State: Initialized, Role: FOLLOWER
I20260812 06:17:05.822046  2407 consensus_queue.cc:260] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [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: "c06cd7a7106546ebbc23770b26fbdcb0" member_type: VOTER }
I20260812 06:17:05.822213  2407 raft_consensus.cc:399] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:05.822297  2407 raft_consensus.cc:493] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:05.822461  2407 raft_consensus.cc:3060] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:05.823248  2407 raft_consensus.cc:515] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c06cd7a7106546ebbc23770b26fbdcb0" member_type: VOTER }
I20260812 06:17:05.823716  2407 leader_election.cc:304] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [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: c06cd7a7106546ebbc23770b26fbdcb0; no voters: 
I20260812 06:17:05.824025  2407 leader_election.cc:290] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:05.824156  2411 raft_consensus.cc:2804] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:05.824410  2411 raft_consensus.cc:697] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [term 1 LEADER]: Becoming Leader. State: Replica: c06cd7a7106546ebbc23770b26fbdcb0, State: Running, Role: LEADER
I20260812 06:17:05.824828  2411 consensus_queue.cc:237] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [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: "c06cd7a7106546ebbc23770b26fbdcb0" member_type: VOTER }
I20260812 06:17:05.825055  2407 sys_catalog.cc:565] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:05.826831  2412 sys_catalog.cc:455] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "c06cd7a7106546ebbc23770b26fbdcb0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c06cd7a7106546ebbc23770b26fbdcb0" member_type: VOTER } }
I20260812 06:17:05.826889  2414 sys_catalog.cc:455] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader c06cd7a7106546ebbc23770b26fbdcb0. Latest consensus state: current_term: 1 leader_uuid: "c06cd7a7106546ebbc23770b26fbdcb0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c06cd7a7106546ebbc23770b26fbdcb0" member_type: VOTER } }
I20260812 06:17:05.826993  2412 sys_catalog.cc:458] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:05.826994  2414 sys_catalog.cc:458] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:05.827301  2319 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:05.827368  2432 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:05.830016  2432 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:05.834517  2432 catalog_manager.cc:1383] Generated new cluster ID: 215fd67184ee4a70b4e27cff652ac2a2
I20260812 06:17:05.834583  2432 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:05.877331  2432 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:05.878243  2432 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:05.884025  2432 catalog_manager.cc:6092] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0: Generated new TSK 0
I20260812 06:17:05.884641  2432 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:05.891960  2319 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:05.894619  2438 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:17:05.894635  2441 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:05.894630  2437 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:05.894928  2319 server_base.cc:1061] running on GCE node
I20260812 06:17:05.895227  2319 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:05.895279  2319 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:05.895329  2319 hybrid_clock.cc:648] HybridClock initialized: now 1786515425895329 us; error 0 us; skew 500 ppm
I20260812 06:17:05.896240  2319 webserver.cc:533] Webserver started at http://127.2.67.193:39797/ using document root <none> and password file <none>
I20260812 06:17:05.896404  2319 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:05.896463  2319 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:05.896546  2319 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:05.896965  2319 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/instance:
uuid: "322de5ecd43b4bebb2d5ba6598b7fffd"
format_stamp: "Formatted at 2026-08-12 06:17:05 on dist-test-slave-7c35"
I20260812 06:17:05.898710  2319 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:05.899784  2448 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:05.900032  2319 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:05.900127  2319 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root
uuid: "322de5ecd43b4bebb2d5ba6598b7fffd"
format_stamp: "Formatted at 2026-08-12 06:17:05 on dist-test-slave-7c35"
I20260812 06:17:05.900214  2319 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:05.912412  2319 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:05.912808  2319 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:05.913282  2319 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:05.914113  2319 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:05.914189  2319 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:05.914261  2319 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:05.914312  2319 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:05.921018  2319 rpc_server.cc:307] RPC server started. Bound to: 127.2.67.193:32885
I20260812 06:17:05.921087  2532 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.67.193:32885 every 8 connection(s)
I20260812 06:17:05.931197  2533 heartbeater.cc:344] Connected to a master server at 127.2.67.254:34539
I20260812 06:17:05.931435  2533 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:05.931851  2533 heartbeater.cc:507] Master 127.2.67.254:34539 requested a full tablet report, sending...
I20260812 06:17:05.933296  2359 ts_manager.cc:194] Registered new tserver with Master: 322de5ecd43b4bebb2d5ba6598b7fffd (127.2.67.193:32885)
I20260812 06:17:05.934019  2319 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012357013s
I20260812 06:17:05.934756  2359 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46294
I20260812 06:17:05.942996  2359 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46298:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:05.956717  2482 tablet_service.cc:1511] Processing CreateTablet for tablet 06d86895a08045c482d31387fad397f4 (DEFAULT_TABLE table=heavy-update-compaction-test [id=74e13ee192994508b1e19c3fd57488ad]), partition=
I20260812 06:17:05.957150  2482 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 06d86895a08045c482d31387fad397f4. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:05.959741  2549 tablet_bootstrap.cc:492] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Bootstrap starting.
I20260812 06:17:05.960688  2549 tablet_bootstrap.cc:654] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:05.962167  2549 tablet_bootstrap.cc:492] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: No bootstrap required, opened a new log
I20260812 06:17:05.962296  2549 ts_tablet_manager.cc:1403] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:05.962726  2549 raft_consensus.cc:359] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "322de5ecd43b4bebb2d5ba6598b7fffd" member_type: VOTER last_known_addr { host: "127.2.67.193" port: 32885 } }
I20260812 06:17:05.962846  2549 raft_consensus.cc:385] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:05.962921  2549 raft_consensus.cc:740] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 322de5ecd43b4bebb2d5ba6598b7fffd, State: Initialized, Role: FOLLOWER
I20260812 06:17:05.963069  2549 consensus_queue.cc:260] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd [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: "322de5ecd43b4bebb2d5ba6598b7fffd" member_type: VOTER last_known_addr { host: "127.2.67.193" port: 32885 } }
I20260812 06:17:05.963187  2549 raft_consensus.cc:399] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:05.963236  2549 raft_consensus.cc:493] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:05.963289  2549 raft_consensus.cc:3060] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:05.964402  2549 raft_consensus.cc:515] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "322de5ecd43b4bebb2d5ba6598b7fffd" member_type: VOTER last_known_addr { host: "127.2.67.193" port: 32885 } }
I20260812 06:17:05.964556  2549 leader_election.cc:304] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd [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: 322de5ecd43b4bebb2d5ba6598b7fffd; no voters: 
I20260812 06:17:05.964764  2549 leader_election.cc:290] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:05.964895  2551 raft_consensus.cc:2804] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:05.965160  2549 ts_tablet_manager.cc:1434] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:17:05.965175  2551 raft_consensus.cc:697] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd [term 1 LEADER]: Becoming Leader. State: Replica: 322de5ecd43b4bebb2d5ba6598b7fffd, State: Running, Role: LEADER
I20260812 06:17:05.965391  2551 consensus_queue.cc:237] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd [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: "322de5ecd43b4bebb2d5ba6598b7fffd" member_type: VOTER last_known_addr { host: "127.2.67.193" port: 32885 } }
I20260812 06:17:05.965865  2533 heartbeater.cc:499] Master 127.2.67.254:34539 was elected leader, sending a full tablet report...
I20260812 06:17:05.968596  2359 catalog_manager.cc:5719] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd reported cstate change: term changed from 0 to 1, leader changed from <none> to 322de5ecd43b4bebb2d5ba6598b7fffd (127.2.67.193). New cstate: current_term: 1 leader_uuid: "322de5ecd43b4bebb2d5ba6598b7fffd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "322de5ecd43b4bebb2d5ba6598b7fffd" member_type: VOTER last_known_addr { host: "127.2.67.193" port: 32885 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:06.039311  2319 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.023s	sys 0.008s
I20260812 06:17:06.172101  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushMRSOp(06d86895a08045c482d31387fad397f4): perf score=19.054940
I20260812 06:17:06.354954  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushMRSOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.183s	user 0.145s	sys 0.036s Metrics: {"bytes_written":12963878,"cfile_init":1,"compiler_manager_pool.queue_time_us":201,"delete_count":0,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":261,"dirs.run_wall_time_us":890,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45029,"lbm_writes_lt_1ms":773,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":225536,"thread_start_us":134,"threads_started":1,"update_count":1580}
I20260812 06:17:06.356256  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling LogGCOp(06d86895a08045c482d31387fad397f4): free 20743880 bytes of WAL
I20260812 06:17:06.356575  2453 log_reader.cc:385] T 06d86895a08045c482d31387fad397f4: removed 2 log segments from log reader
I20260812 06:17:06.356652  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000001 (ops 1-6)
I20260812 06:17:06.356721  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000002 (ops 7-11)
I20260812 06:17:06.361809  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: LogGCOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:06.362169  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=3.181125
I20260812 06:17:06.384385  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.022s	user 0.011s	sys 0.010s Metrics: {"bytes_written":4430858,"delete_count":0,"lbm_write_time_us":6374,"lbm_writes_lt_1ms":111,"reinsert_count":0,"update_count":540}
I20260812 06:17:06.384825  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=1.196750
I20260812 06:17:06.393307  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3118055,"delete_count":0,"lbm_write_time_us":3206,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:17:06.393766  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling UndoDeltaBlockGCOp(06d86895a08045c482d31387fad397f4): 16411392 bytes on disk
I20260812 06:17:06.394290  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: UndoDeltaBlockGCOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:17:06.394680  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:06.558531  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.164s	user 0.107s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774791,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":854,"lbm_read_time_us":12057,"lbm_reads_lt_1ms":569,"lbm_write_time_us":25290,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":311,"threads_started":5,"update_count":2500}
I20260812 06:17:06.559199  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=10.126437
I20260812 06:17:06.607575  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.048s	user 0.015s	sys 0.033s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21116,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:06.608006  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:06.621897  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.014s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5232,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.622334  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:06.748383  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.126s	user 0.107s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":985,"lbm_read_time_us":9160,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24634,"lbm_writes_lt_1ms":443,"mutex_wait_us":317,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:06.748905  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=10.126437
I20260812 06:17:06.791723  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.043s	user 0.018s	sys 0.021s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16254,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:06.792258  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:06.804827  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4424,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.805672  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:06.937662  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.132s	user 0.110s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":671,"lbm_read_time_us":9031,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26370,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:06.938328  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=11.118625
I20260812 06:17:06.968858  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.030s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13009,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:06.969314  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:06.982646  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4637,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:06.983086  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:07.125492  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.142s	user 0.104s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":500,"lbm_read_time_us":8980,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26504,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:17:07.126081  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=10.126437
I20260812 06:17:07.187496  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.061s	user 0.041s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19760,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:07.188120  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:07.198606  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4108,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.199092  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:07.350360  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.151s	user 0.106s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":297,"lbm_read_time_us":10085,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24687,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:07.350950  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=10.126437
I20260812 06:17:07.395182  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.044s	user 0.031s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17295,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:07.395668  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:07.498368  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.102s	user 0.070s	sys 0.033s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":197,"lbm_read_time_us":6749,"lbm_reads_lt_1ms":363,"lbm_write_time_us":18192,"lbm_writes_lt_1ms":343,"mutex_wait_us":37,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:17:07.499114  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=10.126437
I20260812 06:17:07.544571  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.045s	user 0.017s	sys 0.024s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":19931,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:07.545053  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:07.555573  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4077,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.556217  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushMRSOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:07.585506  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushMRSOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":1422,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1526,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:07.586351  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling LogGCOp(06d86895a08045c482d31387fad397f4): free 112239278 bytes of WAL
I20260812 06:17:07.586627  2453 log_reader.cc:385] T 06d86895a08045c482d31387fad397f4: removed 11 log segments from log reader
I20260812 06:17:07.586688  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000003 (ops 12-16)
I20260812 06:17:07.586726  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000004 (ops 17-21)
I20260812 06:17:07.586761  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000005 (ops 22-26)
I20260812 06:17:07.586803  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000006 (ops 27-30)
I20260812 06:17:07.586826  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000007 (ops 31-35)
I20260812 06:17:07.586879  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000008 (ops 36-40)
I20260812 06:17:07.586913  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000009 (ops 41-45)
I20260812 06:17:07.586941  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000010 (ops 46-50)
I20260812 06:17:07.586975  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000011 (ops 51-55)
I20260812 06:17:07.586998  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000012 (ops 56-60)
I20260812 06:17:07.587026  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000013 (ops 61-65)
I20260812 06:17:07.614511  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: LogGCOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.028s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:07.615017  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling UndoDeltaBlockGCOp(06d86895a08045c482d31387fad397f4): 448 bytes on disk
I20260812 06:17:07.615546  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: UndoDeltaBlockGCOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:17:07.616092  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:07.642550  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.026s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6098,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.643059  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:07.653174  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3842,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.653734  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:07.826061  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.172s	user 0.140s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877341,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":317,"lbm_read_time_us":11230,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34079,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9600,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:17:07.828375  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=14.095187
I20260812 06:17:07.877774  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.049s	user 0.036s	sys 0.009s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21180,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:07.878295  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:07.893488  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5786,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.894059  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:08.040889  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.147s	user 0.121s	sys 0.024s 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":626,"lbm_read_time_us":8831,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30306,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:17:08.041563  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=11.118625
I20260812 06:17:08.082747  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.041s	user 0.012s	sys 0.024s Metrics: {"bytes_written":13456167,"delete_count":0,"lbm_write_time_us":17395,"lbm_writes_lt_1ms":331,"mutex_wait_us":1039,"reinsert_count":0,"update_count":1640}
I20260812 06:17:08.083400  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=1.196750
I20260812 06:17:08.094889  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":3222,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:17:08.095463  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:08.232896  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.137s	user 0.110s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672250,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1229,"lbm_read_time_us":9029,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23046,"lbm_writes_lt_1ms":443,"mutex_wait_us":357,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:08.233570  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=14.095187
I20260812 06:17:08.290985  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.057s	user 0.026s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":28180,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:17:08.291563  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:08.311887  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.020s	user 0.009s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4258,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:08.312466  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:08.483946  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.171s	user 0.095s	sys 0.070s 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":252,"lbm_read_time_us":13461,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26318,"lbm_writes_lt_1ms":543,"mutex_wait_us":59,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2500}
I20260812 06:17:08.484596  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=14.095187
I20260812 06:17:08.530512  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.046s	user 0.020s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19444,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:08.531112  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:08.545832  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5498,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:08.546319  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:08.707526  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.161s	user 0.107s	sys 0.047s 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":496,"lbm_read_time_us":9668,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27074,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:17:08.708160  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=11.118625
I20260812 06:17:08.749374  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.041s	user 0.013s	sys 0.025s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18910,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:08.749891  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:08.774115  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.021s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:08.774554  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:08.783665  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3487,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:08.784158  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:08.920631  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.136s	user 0.110s	sys 0.025s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":878,"lbm_read_time_us":10112,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27473,"lbm_writes_lt_1ms":543,"mutex_wait_us":697,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:17:08.921274  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=10.126437
I20260812 06:17:08.966224  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.045s	user 0.015s	sys 0.026s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19432,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:08.966943  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:08.994397  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.027s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":10109,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:17:08.994956  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:09.005896  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4183,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.006422  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushMRSOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:09.040553  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushMRSOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":1390,"drs_written":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1797,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:09.041280  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling LogGCOp(06d86895a08045c482d31387fad397f4): free 124710306 bytes of WAL
I20260812 06:17:09.041497  2453 log_reader.cc:385] T 06d86895a08045c482d31387fad397f4: removed 12 log segments from log reader
I20260812 06:17:09.041540  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000014 (ops 66-70)
I20260812 06:17:09.041568  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000015 (ops 71-75)
I20260812 06:17:09.041626  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000016 (ops 76-80)
I20260812 06:17:09.041656  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000017 (ops 81-85)
I20260812 06:17:09.041694  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000018 (ops 86-90)
I20260812 06:17:09.041750  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000019 (ops 91-95)
I20260812 06:17:09.041797  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000020 (ops 96-100)
I20260812 06:17:09.041831  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000021 (ops 101-105)
I20260812 06:17:09.041865  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000022 (ops 106-110)
I20260812 06:17:09.041908  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000023 (ops 111-115)
I20260812 06:17:09.041940  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000024 (ops 116-120)
I20260812 06:17:09.041973  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000025 (ops 121-125)
I20260812 06:17:09.068051  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: LogGCOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:09.068509  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=3.181125
I20260812 06:17:09.085517  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6746,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:09.085920  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:09.102155  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.016s	user 0.004s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3623,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:09.102696  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:09.330703  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.228s	user 0.122s	sys 0.105s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979860,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":224,"lbm_read_time_us":17594,"lbm_reads_lt_1ms":775,"lbm_write_time_us":37051,"lbm_writes_lt_1ms":743,"mutex_wait_us":2,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3840,"thread_start_us":71,"threads_started":1,"update_count":3500}
I20260812 06:17:09.331257  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=14.095187
I20260812 06:17:09.383594  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.052s	user 0.021s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19077,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:09.384207  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:09.395761  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4533,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.396214  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:09.568791  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.172s	user 0.138s	sys 0.034s 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":102,"lbm_read_time_us":14467,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30342,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:09.569842  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling UndoDeltaBlockGCOp(06d86895a08045c482d31387fad397f4): 482 bytes on disk
I20260812 06:17:09.570472  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: UndoDeltaBlockGCOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:17:09.571430  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=11.118625
I20260812 06:17:09.602075  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.030s	user 0.010s	sys 0.017s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":13194,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:09.602603  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:09.627558  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.025s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5044,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:09.628176  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:09.766925  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.139s	user 0.101s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":705,"lbm_read_time_us":8504,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21656,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:17:09.767441  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=11.118625
I20260812 06:17:09.802039  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.034s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":14577,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:09.802726  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:09.815793  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4177,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:09.816222  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:09.941886  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.125s	user 0.102s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":181,"lbm_read_time_us":8136,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24676,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:17:09.942750  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=10.126437
I20260812 06:17:09.987088  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.044s	user 0.016s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16225,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:09.987571  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:09.997303  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3789,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.997936  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:10.126322  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.128s	user 0.096s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":829,"lbm_read_time_us":10178,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24139,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":76288,"update_count":2000}
I20260812 06:17:10.127067  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=10.126437
I20260812 06:17:10.178453  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.051s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13695,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:10.179153  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:10.189287  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4056,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.189698  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:10.335299  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.145s	user 0.103s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1159,"lbm_read_time_us":10806,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21876,"lbm_writes_lt_1ms":443,"mutex_wait_us":323,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:10.335875  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=10.126437
I20260812 06:17:10.373631  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.038s	user 0.022s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14661,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:10.374125  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:10.389422  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5736,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.389948  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:10.517515  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.127s	user 0.102s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":765,"lbm_read_time_us":10831,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23380,"lbm_writes_lt_1ms":443,"mutex_wait_us":370,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2000}
I20260812 06:17:10.518064  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=10.126437
I20260812 06:17:10.562896  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.045s	user 0.013s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15653,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:10.563383  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:10.577895  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5565,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.578487  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushMRSOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:10.611874  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushMRSOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.033s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":200,"dirs.run_wall_time_us":1456,"drs_written":1,"lbm_read_time_us":34,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2053,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:10.612586  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling LogGCOp(06d86895a08045c482d31387fad397f4): free 132571629 bytes of WAL
I20260812 06:17:10.612808  2453 log_reader.cc:385] T 06d86895a08045c482d31387fad397f4: removed 13 log segments from log reader
I20260812 06:17:10.612852  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000026 (ops 126-130)
I20260812 06:17:10.612879  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000027 (ops 131-134)
I20260812 06:17:10.612946  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000028 (ops 135-139)
I20260812 06:17:10.612977  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000029 (ops 140-144)
I20260812 06:17:10.613015  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000030 (ops 145-148)
I20260812 06:17:10.613054  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000031 (ops 149-153)
I20260812 06:17:10.613091  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000032 (ops 154-158)
I20260812 06:17:10.613127  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000033 (ops 159-163)
I20260812 06:17:10.613164  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000034 (ops 164-168)
I20260812 06:17:10.613201  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000035 (ops 169-173)
I20260812 06:17:10.613240  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000036 (ops 174-178)
I20260812 06:17:10.613276  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000037 (ops 179-183)
I20260812 06:17:10.613313  2453 log.cc:1079] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/06d86895a08045c482d31387fad397f4/wal-000000038 (ops 184-188)
I20260812 06:17:10.641711  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: LogGCOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:10.642231  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=3.181125
I20260812 06:17:10.660415  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.018s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6980,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:10.660847  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling UndoDeltaBlockGCOp(06d86895a08045c482d31387fad397f4): 482 bytes on disk
I20260812 06:17:10.661221  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: UndoDeltaBlockGCOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:17:10.661768  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=2.188937
I20260812 06:17:10.670928  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.009s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3474,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:10.671334  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4): perf score=1.000000
I20260812 06:17:10.842617  2319 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.803s	user 1.836s	sys 0.118s
I20260812 06:17:10.845139  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: MajorDeltaCompactionOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.174s	user 0.108s	sys 0.056s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":423,"lbm_read_time_us":11881,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34829,"lbm_writes_lt_1ms":643,"mutex_wait_us":20,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16640,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:17:10.845764  2534 maintenance_manager.cc:419] P 322de5ecd43b4bebb2d5ba6598b7fffd: Scheduling FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4): perf score=14.095187
I20260812 06:17:10.869112  2319 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.026s	user 0.001s	sys 0.000s
I20260812 06:17:10.870049  2319 tablet_server.cc:179] TabletServer@127.2.67.193:0 shutting down...
I20260812 06:17:10.887434  2453 maintenance_manager.cc:643] P 322de5ecd43b4bebb2d5ba6598b7fffd: FlushDeltaMemStoresOp(06d86895a08045c482d31387fad397f4) complete. Timing: real 0.041s	user 0.038s	sys 0.003s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18267,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:10.888077  2319 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:10.888998  2319 tablet_replica.cc:333] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd: stopping tablet replica
I20260812 06:17:10.889227  2319 raft_consensus.cc:2243] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:10.889454  2319 raft_consensus.cc:2272] T 06d86895a08045c482d31387fad397f4 P 322de5ecd43b4bebb2d5ba6598b7fffd [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:10.904909  2319 tablet_server.cc:196] TabletServer@127.2.67.193:0 shutdown complete.
I20260812 06:17:10.909173  2319 master.cc:562] Master@127.2.67.254:34539 shutting down...
I20260812 06:17:10.912529  2319 raft_consensus.cc:2243] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:10.912660  2319 raft_consensus.cc:2272] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:10.912709  2319 tablet_replica.cc:333] T 00000000000000000000000000000000 P c06cd7a7106546ebbc23770b26fbdcb0: stopping tablet replica
I20260812 06:17:10.924777  2319 master.cc:584] Master@127.2.67.254:34539 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5243 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:11.008911  2319 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.67.254:35201
I20260812 06:17:11.009255  2319 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:11.011092  2574 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:11.011111  2575 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:17:11.011307  2577 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:11.011318  2319 server_base.cc:1061] running on GCE node
I20260812 06:17:11.011574  2319 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:11.011612  2319 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:11.011627  2319 hybrid_clock.cc:648] HybridClock initialized: now 1786515431011628 us; error 0 us; skew 500 ppm
I20260812 06:17:11.012440  2319 webserver.cc:533] Webserver started at http://127.2.67.254:39151/ using document root <none> and password file <none>
I20260812 06:17:11.012609  2319 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:11.012653  2319 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:11.012741  2319 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:11.013141  2319 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/master-0-root/instance:
uuid: "0477305a8a4d487db69ec1bfe176a6e4"
format_stamp: "Formatted at 2026-08-12 06:17:11 on dist-test-slave-7c35"
I20260812 06:17:11.014643  2319 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:11.015725  2582 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:11.015973  2319 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:11.016060  2319 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/master-0-root
uuid: "0477305a8a4d487db69ec1bfe176a6e4"
format_stamp: "Formatted at 2026-08-12 06:17:11 on dist-test-slave-7c35"
I20260812 06:17:11.016145  2319 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:11.034389  2319 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:11.034757  2319 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:11.038674  2319 rpc_server.cc:307] RPC server started. Bound to: 127.2.67.254:35201
I20260812 06:17:11.040076  2645 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.67.254:35201 every 8 connection(s)
I20260812 06:17:11.040557  2646 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:11.052800  2646 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4: Bootstrap starting.
I20260812 06:17:11.053573  2646 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:11.054606  2646 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4: No bootstrap required, opened a new log
I20260812 06:17:11.055044  2646 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0477305a8a4d487db69ec1bfe176a6e4" member_type: VOTER }
I20260812 06:17:11.055131  2646 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:11.055153  2646 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0477305a8a4d487db69ec1bfe176a6e4, State: Initialized, Role: FOLLOWER
I20260812 06:17:11.055364  2646 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [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: "0477305a8a4d487db69ec1bfe176a6e4" member_type: VOTER }
I20260812 06:17:11.055441  2646 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:11.055512  2646 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:11.055584  2646 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:11.056275  2646 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0477305a8a4d487db69ec1bfe176a6e4" member_type: VOTER }
I20260812 06:17:11.056468  2646 leader_election.cc:304] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [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: 0477305a8a4d487db69ec1bfe176a6e4; no voters: 
I20260812 06:17:11.056684  2646 leader_election.cc:290] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:11.056829  2652 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:11.057054  2652 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [term 1 LEADER]: Becoming Leader. State: Replica: 0477305a8a4d487db69ec1bfe176a6e4, State: Running, Role: LEADER
I20260812 06:17:11.057189  2652 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [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: "0477305a8a4d487db69ec1bfe176a6e4" member_type: VOTER }
I20260812 06:17:11.057256  2646 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:11.057680  2654 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0477305a8a4d487db69ec1bfe176a6e4. Latest consensus state: current_term: 1 leader_uuid: "0477305a8a4d487db69ec1bfe176a6e4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0477305a8a4d487db69ec1bfe176a6e4" member_type: VOTER } }
I20260812 06:17:11.057667  2653 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0477305a8a4d487db69ec1bfe176a6e4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0477305a8a4d487db69ec1bfe176a6e4" member_type: VOTER } }
I20260812 06:17:11.057806  2654 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:11.057880  2653 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:11.058306  2660 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:11.059064  2660 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:11.059254  2319 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:11.060935  2660 catalog_manager.cc:1383] Generated new cluster ID: 22d02414d9264f5f840b00245c414f4b
I20260812 06:17:11.060992  2660 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:11.080994  2660 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:11.081549  2660 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:11.094571  2660 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4: Generated new TSK 0
I20260812 06:17:11.094758  2660 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:11.123883  2319 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:11.126029  2675 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:11.126065  2676 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:11.126035  2319 server_base.cc:1061] running on GCE node
W20260812 06:17:11.126070  2679 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:11.126444  2319 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:11.126508  2319 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:11.126542  2319 hybrid_clock.cc:648] HybridClock initialized: now 1786515431126541 us; error 0 us; skew 500 ppm
I20260812 06:17:11.127403  2319 webserver.cc:533] Webserver started at http://127.2.67.193:33201/ using document root <none> and password file <none>
I20260812 06:17:11.127584  2319 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:11.127662  2319 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:11.127735  2319 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:11.128104  2319 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/instance:
uuid: "e65b95a3c37144f19e60f602ad37a12e"
format_stamp: "Formatted at 2026-08-12 06:17:11 on dist-test-slave-7c35"
I20260812 06:17:11.129606  2319 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:11.130527  2685 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:11.130767  2319 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:11.130872  2319 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root
uuid: "e65b95a3c37144f19e60f602ad37a12e"
format_stamp: "Formatted at 2026-08-12 06:17:11 on dist-test-slave-7c35"
I20260812 06:17:11.130960  2319 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:11.143359  2319 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:11.143683  2319 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:11.143963  2319 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:11.144428  2319 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:11.144492  2319 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:11.144549  2319 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:11.144599  2319 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:11.149176  2319 rpc_server.cc:307] RPC server started. Bound to: 127.2.67.193:40211
I20260812 06:17:11.149200  2769 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.67.193:40211 every 8 connection(s)
I20260812 06:17:11.157704  2770 heartbeater.cc:344] Connected to a master server at 127.2.67.254:35201
I20260812 06:17:11.157816  2770 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:11.158037  2770 heartbeater.cc:507] Master 127.2.67.254:35201 requested a full tablet report, sending...
I20260812 06:17:11.158716  2601 ts_manager.cc:194] Registered new tserver with Master: e65b95a3c37144f19e60f602ad37a12e (127.2.67.193:40211)
I20260812 06:17:11.159461  2601 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41100
I20260812 06:17:11.159672  2319 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010010542s
I20260812 06:17:11.166401  2601 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41112:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:11.175246  2719 tablet_service.cc:1511] Processing CreateTablet for tablet 348ad83139b04ec89871a0803ffe6324 (DEFAULT_TABLE table=heavy-update-compaction-test [id=245387256ead4c8798216ae8f7c4f06b]), partition=
I20260812 06:17:11.175523  2719 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 348ad83139b04ec89871a0803ffe6324. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:11.177366  2787 tablet_bootstrap.cc:492] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Bootstrap starting.
I20260812 06:17:11.178231  2787 tablet_bootstrap.cc:654] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:11.179338  2787 tablet_bootstrap.cc:492] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: No bootstrap required, opened a new log
I20260812 06:17:11.179441  2787 ts_tablet_manager.cc:1403] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:11.179813  2787 raft_consensus.cc:359] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e65b95a3c37144f19e60f602ad37a12e" member_type: VOTER last_known_addr { host: "127.2.67.193" port: 40211 } }
I20260812 06:17:11.179934  2787 raft_consensus.cc:385] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:11.180002  2787 raft_consensus.cc:740] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e65b95a3c37144f19e60f602ad37a12e, State: Initialized, Role: FOLLOWER
I20260812 06:17:11.180135  2787 consensus_queue.cc:260] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e [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: "e65b95a3c37144f19e60f602ad37a12e" member_type: VOTER last_known_addr { host: "127.2.67.193" port: 40211 } }
I20260812 06:17:11.180276  2787 raft_consensus.cc:399] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:11.180322  2787 raft_consensus.cc:493] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:11.180362  2787 raft_consensus.cc:3060] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:11.181169  2787 raft_consensus.cc:515] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e65b95a3c37144f19e60f602ad37a12e" member_type: VOTER last_known_addr { host: "127.2.67.193" port: 40211 } }
I20260812 06:17:11.181308  2787 leader_election.cc:304] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e [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: e65b95a3c37144f19e60f602ad37a12e; no voters: 
I20260812 06:17:11.181519  2787 leader_election.cc:290] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:11.181670  2789 raft_consensus.cc:2804] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:11.181856  2770 heartbeater.cc:499] Master 127.2.67.254:35201 was elected leader, sending a full tablet report...
I20260812 06:17:11.181859  2787 ts_tablet_manager.cc:1434] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:11.182183  2789 raft_consensus.cc:697] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e [term 1 LEADER]: Becoming Leader. State: Replica: e65b95a3c37144f19e60f602ad37a12e, State: Running, Role: LEADER
I20260812 06:17:11.182329  2789 consensus_queue.cc:237] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e [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: "e65b95a3c37144f19e60f602ad37a12e" member_type: VOTER last_known_addr { host: "127.2.67.193" port: 40211 } }
I20260812 06:17:11.183764  2601 catalog_manager.cc:5719] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e reported cstate change: term changed from 0 to 1, leader changed from <none> to e65b95a3c37144f19e60f602ad37a12e (127.2.67.193). New cstate: current_term: 1 leader_uuid: "e65b95a3c37144f19e60f602ad37a12e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e65b95a3c37144f19e60f602ad37a12e" member_type: VOTER last_known_addr { host: "127.2.67.193" port: 40211 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:11.241366  2319 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.015s	sys 0.006s
I20260812 06:17:11.400105  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushMRSOp(348ad83139b04ec89871a0803ffe6324): perf score=23.023690
I20260812 06:17:11.547158  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushMRSOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.147s	user 0.110s	sys 0.036s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":884,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39056,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:17:11.547753  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling LogGCOp(348ad83139b04ec89871a0803ffe6324): free 20743880 bytes of WAL
I20260812 06:17:11.547972  2691 log_reader.cc:385] T 348ad83139b04ec89871a0803ffe6324: removed 2 log segments from log reader
I20260812 06:17:11.548014  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000001 (ops 1-6)
I20260812 06:17:11.548043  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000002 (ops 7-11)
I20260812 06:17:11.551968  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: LogGCOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:11.552254  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:11.568876  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6011,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:11.569286  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling UndoDeltaBlockGCOp(348ad83139b04ec89871a0803ffe6324): 20513815 bytes on disk
I20260812 06:17:11.569657  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: UndoDeltaBlockGCOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:17:11.570017  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:11.716007  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.146s	user 0.109s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":376,"lbm_read_time_us":8945,"lbm_reads_lt_1ms":460,"lbm_write_time_us":26411,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":352,"threads_started":5,"update_count":2000}
I20260812 06:17:11.716656  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=10.126437
I20260812 06:17:11.756880  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.040s	user 0.028s	sys 0.009s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16915,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:11.757342  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:11.768507  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3977,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:11.769106  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:11.889520  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.120s	user 0.088s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1056,"lbm_read_time_us":7790,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22221,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":2000}
I20260812 06:17:11.890239  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=10.126437
I20260812 06:17:11.933254  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.043s	user 0.022s	sys 0.018s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14189,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:11.933910  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:11.945859  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4547,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:11.946394  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:12.103404  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.157s	user 0.094s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":329,"lbm_read_time_us":10243,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23733,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:17:12.103940  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=14.095187
I20260812 06:17:12.156693  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.053s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21615,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:12.157219  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:12.167701  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3760,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.168251  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:12.337404  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.169s	user 0.121s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":222,"lbm_read_time_us":10062,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31559,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:12.338002  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=14.095187
I20260812 06:17:12.391561  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.053s	user 0.033s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23144,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:12.392064  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:12.403849  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4357,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.404264  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:12.549911  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.145s	user 0.104s	sys 0.038s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":857,"lbm_read_time_us":9577,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28974,"lbm_writes_lt_1ms":543,"mutex_wait_us":295,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:17:12.550552  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=11.118625
I20260812 06:17:12.590008  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.039s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16967,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:12.590581  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:12.616596  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.026s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5753,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:12.617170  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:12.626726  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3691,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.627153  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:12.769915  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.143s	user 0.096s	sys 0.046s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":149,"lbm_read_time_us":10697,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27071,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":57088,"update_count":2500}
I20260812 06:17:12.770594  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=11.118625
I20260812 06:17:12.800580  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.030s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":13008,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:12.801453  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:12.819830  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.018s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5442,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:12.820423  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushMRSOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:12.873070  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushMRSOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.052s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1316413,"cfile_init":1,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1278,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2285,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":1792}
I20260812 06:17:12.873778  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling LogGCOp(348ad83139b04ec89871a0803ffe6324): free 133024356 bytes of WAL
I20260812 06:17:12.874053  2691 log_reader.cc:385] T 348ad83139b04ec89871a0803ffe6324: removed 13 log segments from log reader
I20260812 06:17:12.874125  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000003 (ops 12-16)
I20260812 06:17:12.874169  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000004 (ops 17-21)
I20260812 06:17:12.874228  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000005 (ops 22-26)
I20260812 06:17:12.874269  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000006 (ops 27-31)
I20260812 06:17:12.874305  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000007 (ops 32-36)
I20260812 06:17:12.874344  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000008 (ops 37-41)
I20260812 06:17:12.874383  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000009 (ops 42-46)
I20260812 06:17:12.874436  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000010 (ops 47-51)
I20260812 06:17:12.874490  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000011 (ops 52-56)
I20260812 06:17:12.874534  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000012 (ops 57-61)
I20260812 06:17:12.874571  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000013 (ops 62-66)
I20260812 06:17:12.874609  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000014 (ops 67-70)
I20260812 06:17:12.874650  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000015 (ops 71-75)
I20260812 06:17:12.899636  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: LogGCOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:12.900111  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=7.149875
I20260812 06:17:12.921994  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.022s	user 0.014s	sys 0.005s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9067,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:12.922555  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:12.938050  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5540,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:12.938521  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:13.132992  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.194s	user 0.141s	sys 0.051s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020731,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":175,"lbm_read_time_us":14366,"lbm_reads_lt_1ms":766,"lbm_write_time_us":39244,"lbm_writes_lt_1ms":743,"mutex_wait_us":44,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:17:13.133723  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling UndoDeltaBlockGCOp(348ad83139b04ec89871a0803ffe6324): 493 bytes on disk
I20260812 06:17:13.134693  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: UndoDeltaBlockGCOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4}
I20260812 06:17:13.135375  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=18.063937
I20260812 06:17:13.195801  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.060s	user 0.047s	sys 0.012s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":27018,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:13.196362  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:13.207636  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3949,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.208082  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:13.367219  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.159s	user 0.115s	sys 0.044s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":194,"lbm_read_time_us":10175,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33636,"lbm_writes_lt_1ms":643,"mutex_wait_us":56,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":3000}
I20260812 06:17:13.367906  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=14.095187
I20260812 06:17:13.421351  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.053s	user 0.037s	sys 0.013s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23374,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.421868  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:13.438038  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5803,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.438542  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:13.588230  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.150s	user 0.118s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":213,"lbm_read_time_us":10736,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27214,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:13.588831  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=14.095187
I20260812 06:17:13.645097  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.056s	user 0.038s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23706,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.645598  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:13.799530  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.154s	user 0.110s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":209,"lbm_read_time_us":10269,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24094,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:17:13.800203  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=14.095187
I20260812 06:17:13.859193  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.059s	user 0.035s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22812,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.859681  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:13.870309  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3956,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.870739  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:14.049500  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.179s	user 0.107s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":579,"lbm_read_time_us":11749,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25752,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2500}
I20260812 06:17:14.050076  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=14.095187
I20260812 06:17:14.100410  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.050s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19407,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:14.100885  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:14.111971  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4062,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.112411  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:14.275230  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.163s	user 0.116s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":751,"lbm_read_time_us":11335,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32748,"lbm_writes_lt_1ms":543,"mutex_wait_us":294,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2500}
I20260812 06:17:14.275784  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=11.118625
I20260812 06:17:14.310333  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.034s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14975,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:14.311088  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:14.324350  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4948,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:14.324900  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushMRSOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:14.375861  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushMRSOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.051s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1316418,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1432,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2135,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:14.376538  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling LogGCOp(348ad83139b04ec89871a0803ffe6324): free 128867434 bytes of WAL
I20260812 06:17:14.376780  2691 log_reader.cc:385] T 348ad83139b04ec89871a0803ffe6324: removed 13 log segments from log reader
I20260812 06:17:14.376822  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000016 (ops 76-80)
I20260812 06:17:14.376850  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000017 (ops 81-85)
I20260812 06:17:14.376890  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000018 (ops 86-90)
I20260812 06:17:14.376938  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000019 (ops 91-94)
I20260812 06:17:14.376957  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000020 (ops 95-99)
I20260812 06:17:14.377015  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000021 (ops 100-104)
I20260812 06:17:14.377077  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000022 (ops 105-108)
I20260812 06:17:14.377118  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000023 (ops 109-113)
I20260812 06:17:14.377161  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000024 (ops 114-118)
I20260812 06:17:14.377202  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000025 (ops 119-123)
I20260812 06:17:14.377240  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000026 (ops 124-128)
I20260812 06:17:14.377277  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000027 (ops 129-132)
I20260812 06:17:14.377314  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000028 (ops 133-137)
I20260812 06:17:14.403702  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: LogGCOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:14.404062  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=7.149875
I20260812 06:17:14.437907  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.034s	user 0.016s	sys 0.015s Metrics: {"bytes_written":8615322,"delete_count":0,"lbm_write_time_us":9584,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:14.438436  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling LogGCOp(348ad83139b04ec89871a0803ffe6324): free 12018006 bytes of WAL
I20260812 06:17:14.438690  2691 log_reader.cc:385] T 348ad83139b04ec89871a0803ffe6324: removed 1 log segments from log reader
I20260812 06:17:14.438748  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000029 (ops 138-142)
I20260812 06:17:14.441735  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: LogGCOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:14.442044  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:14.457903  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5985,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:14.458499  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:14.683099  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.224s	user 0.140s	sys 0.079s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020728,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":468,"lbm_read_time_us":16352,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37027,"lbm_writes_lt_1ms":743,"mutex_wait_us":1,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6784,"thread_start_us":72,"threads_started":1,"update_count":3500}
I20260812 06:17:14.683703  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=18.063937
I20260812 06:17:14.747892  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.064s	user 0.041s	sys 0.016s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26470,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:14.748456  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:14.758567  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3921,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.759366  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:14.953604  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.194s	user 0.124s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2245,"lbm_read_time_us":14279,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31159,"lbm_writes_lt_1ms":643,"mutex_wait_us":1932,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":3000}
I20260812 06:17:14.958652  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=15.087375
I20260812 06:17:15.010763  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.052s	user 0.025s	sys 0.023s Metrics: {"bytes_written":16820141,"delete_count":0,"lbm_write_time_us":23231,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:15.011538  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling UndoDeltaBlockGCOp(348ad83139b04ec89871a0803ffe6324): 492 bytes on disk
I20260812 06:17:15.012125  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: UndoDeltaBlockGCOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:17:15.012965  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:15.040408  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.025s	user 0.010s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6430,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:15.040977  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:15.235888  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.194s	user 0.118s	sys 0.071s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815669,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":725,"lbm_read_time_us":16063,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30985,"lbm_writes_lt_1ms":543,"mutex_wait_us":326,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:17:15.236552  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=15.087375
I20260812 06:17:15.288110  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.051s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":22614,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:15.288626  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:15.301096  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3852,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:15.301699  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:15.461606  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.160s	user 0.124s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815672,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":190,"lbm_read_time_us":11966,"lbm_reads_lt_1ms":568,"lbm_write_time_us":25079,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:17:15.462522  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=14.095187
I20260812 06:17:15.516878  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.054s	user 0.022s	sys 0.030s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19657,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.517671  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:15.538478  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.021s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6750,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.539009  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:15.712414  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.173s	user 0.104s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":145,"lbm_read_time_us":10784,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30845,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2500}
I20260812 06:17:15.713085  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=14.095187
I20260812 06:17:15.771610  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.058s	user 0.021s	sys 0.034s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20572,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.772168  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324): perf score=2.188937
I20260812 06:17:15.787192  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushDeltaMemStoresOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5663,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.787706  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling FlushMRSOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:15.819957  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: FlushMRSOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":40,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":1434,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1922,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:15.820734  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling UndoDeltaBlockGCOp(348ad83139b04ec89871a0803ffe6324): 446 bytes on disk
I20260812 06:17:15.821213  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: UndoDeltaBlockGCOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:17:15.821745  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324): perf score=1.000000
I20260812 06:17:15.926994  2319 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.685s	user 1.683s	sys 0.190s
I20260812 06:17:15.985941  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: MajorDeltaCompactionOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.164s	user 0.136s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":403,"lbm_read_time_us":12444,"lbm_reads_lt_1ms":560,"lbm_write_time_us":27843,"lbm_writes_lt_1ms":543,"mutex_wait_us":72,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2500}
I20260812 06:17:15.986828  2774 maintenance_manager.cc:419] P e65b95a3c37144f19e60f602ad37a12e: Scheduling LogGCOp(348ad83139b04ec89871a0803ffe6324): free 112239552 bytes of WAL
I20260812 06:17:15.987115  2691 log_reader.cc:385] T 348ad83139b04ec89871a0803ffe6324: removed 11 log segments from log reader
I20260812 06:17:15.987172  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000030 (ops 143-147)
I20260812 06:17:15.987253  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000031 (ops 148-152)
I20260812 06:17:15.987304  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000032 (ops 153-157)
I20260812 06:17:15.987346  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000033 (ops 158-162)
I20260812 06:17:15.987385  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000034 (ops 163-167)
I20260812 06:17:15.987428  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000035 (ops 168-172)
I20260812 06:17:15.987491  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000036 (ops 173-177)
I20260812 06:17:15.987526  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000037 (ops 178-182)
I20260812 06:17:15.987566  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000038 (ops 183-187)
I20260812 06:17:15.987604  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000039 (ops 188-192)
I20260812 06:17:15.987641  2691 log.cc:1079] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: Deleting log segment in path: /tmp/dist-test-taskNN5cts/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425755401-2319-0/minicluster-data/ts-0-root/wals/348ad83139b04ec89871a0803ffe6324/wal-000000040 (ops 193-196)
I20260812 06:17:15.998212  2319 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.071s	user 0.003s	sys 0.000s
I20260812 06:17:15.998719  2319 tablet_server.cc:179] TabletServer@127.2.67.193:0 shutting down...
I20260812 06:17:16.012347  2691 maintenance_manager.cc:643] P e65b95a3c37144f19e60f602ad37a12e: LogGCOp(348ad83139b04ec89871a0803ffe6324) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:16.012836  2319 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:16.013077  2319 tablet_replica.cc:333] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e: stopping tablet replica
I20260812 06:17:16.013221  2319 raft_consensus.cc:2243] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:16.013379  2319 raft_consensus.cc:2272] T 348ad83139b04ec89871a0803ffe6324 P e65b95a3c37144f19e60f602ad37a12e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:16.018208  2319 tablet_server.cc:196] TabletServer@127.2.67.193:0 shutdown complete.
I20260812 06:17:16.030297  2319 master.cc:562] Master@127.2.67.254:35201 shutting down...
I20260812 06:17:16.033540  2319 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:16.033715  2319 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:16.033804  2319 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0477305a8a4d487db69ec1bfe176a6e4: stopping tablet replica
I20260812 06:17:16.045931  2319 master.cc:584] Master@127.2.67.254:35201 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5115 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10360 ms total)

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