[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:39.695892 18401 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.17.248.126:35737
I20260812 06:18:39.696874 18401 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:39.697485 18401 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:39.703305 18412 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:39.703375 18401 server_base.cc:1061] running on GCE node
W20260812 06:18:39.703315 18419 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:39.703543 18411 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:39.704028 18401 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:39.704120 18401 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:39.704164 18401 hybrid_clock.cc:648] HybridClock initialized: now 1786515519704161 us; error 0 us; skew 500 ppm
I20260812 06:18:39.705888 18401 webserver.cc:533] Webserver started at http://127.17.248.126:36577/ using document root <none> and password file <none>
I20260812 06:18:39.706396 18401 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:39.706458 18401 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:39.706668 18401 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:39.708231 18401 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/master-0-root/instance:
uuid: "47f062bc60f84ee9ab91c2ac107daea2"
format_stamp: "Formatted at 2026-08-12 06:18:39 on dist-test-slave-gjw7"
I20260812 06:18:39.711540 18401 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:18:39.713404 18428 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:39.714337 18401 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:39.714437 18401 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/master-0-root
uuid: "47f062bc60f84ee9ab91c2ac107daea2"
format_stamp: "Formatted at 2026-08-12 06:18:39 on dist-test-slave-gjw7"
I20260812 06:18:39.714517 18401 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:39.739717 18401 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:39.740317 18401 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:39.740460 18401 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:39.747481 18528 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.248.126:35737 every 8 connection(s)
I20260812 06:18:39.747479 18401 rpc_server.cc:307] RPC server started. Bound to: 127.17.248.126:35737
I20260812 06:18:39.749630 18531 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:39.754714 18531 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2: Bootstrap starting.
I20260812 06:18:39.756899 18531 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:39.757761 18531 log.cc:826] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:39.759258 18531 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2: No bootstrap required, opened a new log
I20260812 06:18:39.761957 18531 raft_consensus.cc:359] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "47f062bc60f84ee9ab91c2ac107daea2" member_type: VOTER }
I20260812 06:18:39.762110 18531 raft_consensus.cc:385] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:39.762166 18531 raft_consensus.cc:740] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 47f062bc60f84ee9ab91c2ac107daea2, State: Initialized, Role: FOLLOWER
I20260812 06:18:39.762712 18531 consensus_queue.cc:260] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [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: "47f062bc60f84ee9ab91c2ac107daea2" member_type: VOTER }
I20260812 06:18:39.762849 18531 raft_consensus.cc:399] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:39.762914 18531 raft_consensus.cc:493] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:39.763032 18531 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:39.763756 18531 raft_consensus.cc:515] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "47f062bc60f84ee9ab91c2ac107daea2" member_type: VOTER }
I20260812 06:18:39.764151 18531 leader_election.cc:304] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [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: 47f062bc60f84ee9ab91c2ac107daea2; no voters: 
I20260812 06:18:39.764430 18531 leader_election.cc:290] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:39.764605 18544 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:39.764806 18544 raft_consensus.cc:697] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [term 1 LEADER]: Becoming Leader. State: Replica: 47f062bc60f84ee9ab91c2ac107daea2, State: Running, Role: LEADER
I20260812 06:18:39.765202 18544 consensus_queue.cc:237] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [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: "47f062bc60f84ee9ab91c2ac107daea2" member_type: VOTER }
I20260812 06:18:39.765305 18531 sys_catalog.cc:565] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:39.767060 18548 sys_catalog.cc:455] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 47f062bc60f84ee9ab91c2ac107daea2. Latest consensus state: current_term: 1 leader_uuid: "47f062bc60f84ee9ab91c2ac107daea2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "47f062bc60f84ee9ab91c2ac107daea2" member_type: VOTER } }
I20260812 06:18:39.767050 18547 sys_catalog.cc:455] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "47f062bc60f84ee9ab91c2ac107daea2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "47f062bc60f84ee9ab91c2ac107daea2" member_type: VOTER } }
I20260812 06:18:39.767185 18548 sys_catalog.cc:458] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:39.767189 18547 sys_catalog.cc:458] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:39.767433 18401 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:18:39.769570 18572 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:39.769631 18572 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:39.769708 18569 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:39.770617 18569 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:39.775110 18569 catalog_manager.cc:1383] Generated new cluster ID: 13fa6497eaed4673b578317aa92468da
I20260812 06:18:39.775162 18569 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:39.779840 18569 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:39.780597 18569 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:39.807749 18569 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2: Generated new TSK 0
I20260812 06:18:39.808436 18569 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:39.832158 18401 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:39.835126 18585 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:39.835302 18401 server_base.cc:1061] running on GCE node
W20260812 06:18:39.835125 18590 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:39.835141 18587 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:39.835631 18401 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:39.835677 18401 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:39.835692 18401 hybrid_clock.cc:648] HybridClock initialized: now 1786515519835692 us; error 0 us; skew 500 ppm
I20260812 06:18:39.836555 18401 webserver.cc:533] Webserver started at http://127.17.248.65:38367/ using document root <none> and password file <none>
I20260812 06:18:39.836730 18401 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:39.836781 18401 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:39.836855 18401 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:39.837229 18401 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/instance:
uuid: "15f3582c832c400e87a21a511bfcf28d"
format_stamp: "Formatted at 2026-08-12 06:18:39 on dist-test-slave-gjw7"
I20260812 06:18:39.838692 18401 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:39.839591 18598 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:39.839840 18401 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:39.839910 18401 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root
uuid: "15f3582c832c400e87a21a511bfcf28d"
format_stamp: "Formatted at 2026-08-12 06:18:39 on dist-test-slave-gjw7"
I20260812 06:18:39.839978 18401 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:39.852711 18401 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:39.853389 18401 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:39.853863 18401 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:39.854744 18401 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:39.854795 18401 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:39.854842 18401 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:39.854872 18401 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:39.860737 18401 rpc_server.cc:307] RPC server started. Bound to: 127.17.248.65:36535
I20260812 06:18:39.860934 18705 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.248.65:36535 every 8 connection(s)
I20260812 06:18:39.873544 18706 heartbeater.cc:344] Connected to a master server at 127.17.248.126:35737
I20260812 06:18:39.873791 18706 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:39.874274 18706 heartbeater.cc:507] Master 127.17.248.126:35737 requested a full tablet report, sending...
I20260812 06:18:39.875691 18468 ts_manager.cc:194] Registered new tserver with Master: 15f3582c832c400e87a21a511bfcf28d (127.17.248.65:36535)
I20260812 06:18:39.875929 18401 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014536763s
I20260812 06:18:39.876937 18468 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55858
I20260812 06:18:39.890112 18468 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55872:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:39.903684 18644 tablet_service.cc:1511] Processing CreateTablet for tablet 657a548b1d374f3aa5a500dea754a1fe (DEFAULT_TABLE table=heavy-update-compaction-test [id=ed3ace342c504a0bbaf066e50e113909]), partition=
I20260812 06:18:39.904166 18644 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 657a548b1d374f3aa5a500dea754a1fe. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:39.906975 18737 tablet_bootstrap.cc:492] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Bootstrap starting.
I20260812 06:18:39.908171 18737 tablet_bootstrap.cc:654] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:39.909181 18737 tablet_bootstrap.cc:492] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: No bootstrap required, opened a new log
I20260812 06:18:39.909271 18737 ts_tablet_manager.cc:1403] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:39.909713 18737 raft_consensus.cc:359] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "15f3582c832c400e87a21a511bfcf28d" member_type: VOTER last_known_addr { host: "127.17.248.65" port: 36535 } }
I20260812 06:18:39.909812 18737 raft_consensus.cc:385] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:39.909835 18737 raft_consensus.cc:740] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 15f3582c832c400e87a21a511bfcf28d, State: Initialized, Role: FOLLOWER
I20260812 06:18:39.909970 18737 consensus_queue.cc:260] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d [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: "15f3582c832c400e87a21a511bfcf28d" member_type: VOTER last_known_addr { host: "127.17.248.65" port: 36535 } }
I20260812 06:18:39.910061 18737 raft_consensus.cc:399] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:39.910149 18737 raft_consensus.cc:493] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:39.910210 18737 raft_consensus.cc:3060] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:39.910984 18737 raft_consensus.cc:515] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "15f3582c832c400e87a21a511bfcf28d" member_type: VOTER last_known_addr { host: "127.17.248.65" port: 36535 } }
I20260812 06:18:39.911104 18737 leader_election.cc:304] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d [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: 15f3582c832c400e87a21a511bfcf28d; no voters: 
I20260812 06:18:39.911290 18737 leader_election.cc:290] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:39.911394 18741 raft_consensus.cc:2804] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:39.911626 18741 raft_consensus.cc:697] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d [term 1 LEADER]: Becoming Leader. State: Replica: 15f3582c832c400e87a21a511bfcf28d, State: Running, Role: LEADER
I20260812 06:18:39.911767 18741 consensus_queue.cc:237] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d [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: "15f3582c832c400e87a21a511bfcf28d" member_type: VOTER last_known_addr { host: "127.17.248.65" port: 36535 } }
I20260812 06:18:39.912226 18706 heartbeater.cc:499] Master 127.17.248.126:35737 was elected leader, sending a full tablet report...
I20260812 06:18:39.911615 18737 ts_tablet_manager.cc:1434] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:39.914443 18468 catalog_manager.cc:5719] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d reported cstate change: term changed from 0 to 1, leader changed from <none> to 15f3582c832c400e87a21a511bfcf28d (127.17.248.65). New cstate: current_term: 1 leader_uuid: "15f3582c832c400e87a21a511bfcf28d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "15f3582c832c400e87a21a511bfcf28d" member_type: VOTER last_known_addr { host: "127.17.248.65" port: 36535 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:39.972448 18401 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.013s	sys 0.010s
I20260812 06:18:40.111925 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushMRSOp(657a548b1d374f3aa5a500dea754a1fe): perf score=19.054940
I20260812 06:18:40.268273 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushMRSOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.156s	user 0.116s	sys 0.032s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":671,"delete_count":0,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":1044,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37640,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":103,"threads_started":1,"update_count":1500}
I20260812 06:18:40.269199 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling LogGCOp(657a548b1d374f3aa5a500dea754a1fe): free 20743880 bytes of WAL
I20260812 06:18:40.269477 18605 log_reader.cc:385] T 657a548b1d374f3aa5a500dea754a1fe: removed 2 log segments from log reader
I20260812 06:18:40.269534 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000001 (ops 1-6)
I20260812 06:18:40.269624 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000002 (ops 7-11)
I20260812 06:18:40.273041 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: LogGCOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:40.273345 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:40.286206 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4617,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.286818 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:40.409070 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.122s	user 0.094s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":359,"lbm_read_time_us":6826,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20718,"lbm_writes_lt_1ms":443,"mutex_wait_us":320,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":323,"threads_started":5,"update_count":2000}
I20260812 06:18:40.409554 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=10.126437
I20260812 06:18:40.449965 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.040s	user 0.013s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16397,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:40.450418 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling UndoDeltaBlockGCOp(657a548b1d374f3aa5a500dea754a1fe): 16411396 bytes on disk
I20260812 06:18:40.450843 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: UndoDeltaBlockGCOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:18:40.451238 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:40.554797 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.103s	user 0.079s	sys 0.024s 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":978,"lbm_read_time_us":5539,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19105,"lbm_writes_lt_1ms":343,"mutex_wait_us":307,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":1500}
I20260812 06:18:40.555388 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=10.126437
I20260812 06:18:40.586840 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.031s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13195,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:18:40.587370 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:40.691817 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.104s	user 0.087s	sys 0.012s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":282,"lbm_read_time_us":6379,"lbm_reads_lt_1ms":367,"lbm_write_time_us":15633,"lbm_writes_lt_1ms":343,"mutex_wait_us":34,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:18:40.692433 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=10.126437
I20260812 06:18:40.724522 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.032s	user 0.022s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11709,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:40.725060 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:40.830440 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.105s	user 0.086s	sys 0.016s 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":1021,"lbm_read_time_us":5942,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20109,"lbm_writes_lt_1ms":343,"mutex_wait_us":309,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:18:40.830974 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=10.126437
I20260812 06:18:40.869364 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.038s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16835,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:40.869792 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:40.879465 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3492,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.880002 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:40.996392 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.116s	user 0.104s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":306,"lbm_read_time_us":8086,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22141,"lbm_writes_lt_1ms":443,"mutex_wait_us":99,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:40.996847 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=10.126437
I20260812 06:18:41.040139 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.043s	user 0.011s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12513,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:41.040674 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:41.056412 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6004,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.056877 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:41.195336 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.138s	user 0.098s	sys 0.040s 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":234,"lbm_read_time_us":11633,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21600,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.196007 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=10.126437
I20260812 06:18:41.233595 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.037s	user 0.018s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15796,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:41.234064 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:41.244269 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3702,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.244750 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:41.367488 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.123s	user 0.098s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":844,"lbm_read_time_us":7968,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23258,"lbm_writes_lt_1ms":443,"mutex_wait_us":250,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:41.368155 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=10.126437
I20260812 06:18:41.407680 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.039s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15164,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:41.408190 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:41.423589 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.015s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4269,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.424119 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushMRSOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:41.473438 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushMRSOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.049s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":270,"dirs.run_wall_time_us":1392,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1587,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:41.474248 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling LogGCOp(657a548b1d374f3aa5a500dea754a1fe): free 112692365 bytes of WAL
I20260812 06:18:41.474455 18605 log_reader.cc:385] T 657a548b1d374f3aa5a500dea754a1fe: removed 11 log segments from log reader
I20260812 06:18:41.474499 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000003 (ops 12-16)
I20260812 06:18:41.474526 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000004 (ops 17-21)
I20260812 06:18:41.474555 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000005 (ops 22-26)
I20260812 06:18:41.474586 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000006 (ops 27-31)
I20260812 06:18:41.474618 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000007 (ops 32-36)
I20260812 06:18:41.474651 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000008 (ops 37-41)
I20260812 06:18:41.474691 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000009 (ops 42-46)
I20260812 06:18:41.474725 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000010 (ops 47-51)
I20260812 06:18:41.474745 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000011 (ops 52-56)
I20260812 06:18:41.474776 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000012 (ops 57-61)
I20260812 06:18:41.474808 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000013 (ops 62-66)
I20260812 06:18:41.495102 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: LogGCOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.021s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:18:41.495455 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling UndoDeltaBlockGCOp(657a548b1d374f3aa5a500dea754a1fe): 472 bytes on disk
I20260812 06:18:41.495863 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: UndoDeltaBlockGCOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:18:41.496400 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=7.149875
I20260812 06:18:41.514905 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.018s	user 0.005s	sys 0.012s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":7621,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:41.515293 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling LogGCOp(657a548b1d374f3aa5a500dea754a1fe): free 11564875 bytes of WAL
I20260812 06:18:41.515466 18605 log_reader.cc:385] T 657a548b1d374f3aa5a500dea754a1fe: removed 1 log segments from log reader
I20260812 06:18:41.515507 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000014 (ops 67-70)
I20260812 06:18:41.517277 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: LogGCOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:41.517761 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:41.532320 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.014s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4234,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:41.532749 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:41.707062 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.174s	user 0.134s	sys 0.038s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979742,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":428,"lbm_read_time_us":11635,"lbm_reads_lt_1ms":770,"lbm_write_time_us":32251,"lbm_writes_lt_1ms":743,"mutex_wait_us":52,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":22272,"thread_start_us":73,"threads_started":1,"update_count":3500}
I20260812 06:18:41.708984 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=15.087375
I20260812 06:18:41.757570 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.048s	user 0.034s	sys 0.013s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":20595,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:41.758068 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:41.775508 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.017s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4090,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.775952 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:41.784848 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3350,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:41.785207 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:41.978024 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.193s	user 0.117s	sys 0.069s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":417,"lbm_read_time_us":13669,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34094,"lbm_writes_lt_1ms":643,"mutex_wait_us":30,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":3000}
I20260812 06:18:41.978540 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=14.095187
I20260812 06:18:42.036408 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.058s	user 0.022s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18629,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:42.037014 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:42.046974 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3769,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.047444 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:42.191749 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.144s	user 0.092s	sys 0.052s 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":141,"lbm_read_time_us":10918,"lbm_reads_lt_1ms":572,"lbm_write_time_us":23728,"lbm_writes_lt_1ms":543,"mutex_wait_us":18,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2500}
I20260812 06:18:42.193679 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=10.126437
I20260812 06:18:42.224718 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.031s	user 0.024s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12934,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:18:42.227500 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:42.243464 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5837,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.244190 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:42.370184 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.126s	user 0.090s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":500,"lbm_read_time_us":7084,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24960,"lbm_writes_lt_1ms":443,"mutex_wait_us":260,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:18:42.370683 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=10.126437
I20260812 06:18:42.413424 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.043s	user 0.024s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12008,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:42.413940 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:42.428529 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.429102 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:42.537317 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.108s	user 0.094s	sys 0.013s 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":2638,"lbm_read_time_us":7693,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20040,"lbm_writes_lt_1ms":443,"mutex_wait_us":650,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:42.537892 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=10.126437
I20260812 06:18:42.575628 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.038s	user 0.011s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14609,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:42.576141 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:42.588996 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.013s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4539,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.589479 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:42.705971 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.116s	user 0.108s	sys 0.008s 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":759,"lbm_read_time_us":8898,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21972,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2000}
I20260812 06:18:42.709091 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=10.126437
I20260812 06:18:42.754856 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.045s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16124,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:42.755314 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:42.764950 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3673,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.765443 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushMRSOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:42.804948 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushMRSOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.039s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":186,"dirs.run_wall_time_us":1396,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1316,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:42.805816 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling LogGCOp(657a548b1d374f3aa5a500dea754a1fe): free 121006384 bytes of WAL
I20260812 06:18:42.806074 18605 log_reader.cc:385] T 657a548b1d374f3aa5a500dea754a1fe: removed 12 log segments from log reader
I20260812 06:18:42.806136 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000015 (ops 71-75)
I20260812 06:18:42.806195 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000016 (ops 76-80)
I20260812 06:18:42.806236 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000017 (ops 81-85)
I20260812 06:18:42.806273 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000018 (ops 86-90)
I20260812 06:18:42.806311 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000019 (ops 91-94)
I20260812 06:18:42.806347 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000020 (ops 95-99)
I20260812 06:18:42.806391 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000021 (ops 100-104)
I20260812 06:18:42.806427 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000022 (ops 105-109)
I20260812 06:18:42.806468 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000023 (ops 110-114)
I20260812 06:18:42.806509 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000024 (ops 115-119)
I20260812 06:18:42.806551 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000025 (ops 120-124)
I20260812 06:18:42.806587 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000026 (ops 125-129)
I20260812 06:18:42.828310 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: LogGCOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.022s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:18:42.828728 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=3.181125
I20260812 06:18:42.850548 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.022s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4511,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:42.850977 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling UndoDeltaBlockGCOp(657a548b1d374f3aa5a500dea754a1fe): 462 bytes on disk
I20260812 06:18:42.851377 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: UndoDeltaBlockGCOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4}
I20260812 06:18:42.851887 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:42.860296 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3106,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:42.860769 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:43.045540 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.185s	user 0.119s	sys 0.063s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":114,"lbm_read_time_us":12843,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32372,"lbm_writes_lt_1ms":643,"mutex_wait_us":16,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10752,"thread_start_us":69,"threads_started":1,"update_count":3000}
I20260812 06:18:43.046095 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=14.095187
I20260812 06:18:43.102937 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.057s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19223,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:43.103420 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:43.113268 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3601,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.113708 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:43.260787 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.147s	user 0.118s	sys 0.027s 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":967,"lbm_read_time_us":10163,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25649,"lbm_writes_lt_1ms":543,"mutex_wait_us":268,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2500}
I20260812 06:18:43.261431 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=11.118625
I20260812 06:18:43.302932 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.041s	user 0.012s	sys 0.028s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14785,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:43.303459 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:43.315817 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4378,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:43.316352 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:43.453368 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.137s	user 0.110s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":268,"lbm_read_time_us":8698,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24162,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:43.454092 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=11.118625
I20260812 06:18:43.484858 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.031s	user 0.008s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13219,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:43.485638 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:43.499583 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5281,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:43.500029 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:43.612854 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.113s	user 0.099s	sys 0.011s 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":250,"lbm_read_time_us":7625,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20534,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:18:43.613427 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=10.126437
I20260812 06:18:43.648723 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.033s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14109,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:43.649245 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:43.660296 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4056,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.660769 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:43.779981 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.118s	user 0.076s	sys 0.041s 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":769,"lbm_read_time_us":7861,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22581,"lbm_writes_lt_1ms":443,"mutex_wait_us":286,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2000}
I20260812 06:18:43.780591 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=10.126437
I20260812 06:18:43.827683 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.047s	user 0.034s	sys 0.010s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15957,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:43.828197 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:43.838239 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3642,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.838660 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:43.975823 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.137s	user 0.096s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":623,"lbm_read_time_us":9902,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23602,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":275,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2000}
I20260812 06:18:43.976491 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=10.126437
I20260812 06:18:44.014953 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.038s	user 0.011s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14168,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:44.015388 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:44.025542 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3765,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.026157 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:44.137624 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.111s	user 0.099s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":318,"lbm_read_time_us":7124,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21145,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17664,"update_count":2000}
I20260812 06:18:44.138211 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=10.126437
I20260812 06:18:44.182200 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.044s	user 0.032s	sys 0.001s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14493,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:44.182636 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:44.192739 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3736,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.193333 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushMRSOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:44.226984 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushMRSOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.033s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":160,"dirs.run_wall_time_us":1169,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1821,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:44.227715 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling LogGCOp(657a548b1d374f3aa5a500dea754a1fe): free 121006749 bytes of WAL
I20260812 06:18:44.227939 18605 log_reader.cc:385] T 657a548b1d374f3aa5a500dea754a1fe: removed 12 log segments from log reader
I20260812 06:18:44.227999 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000027 (ops 130-134)
I20260812 06:18:44.228039 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000028 (ops 135-139)
I20260812 06:18:44.228075 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000029 (ops 140-144)
I20260812 06:18:44.228097 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000030 (ops 145-149)
I20260812 06:18:44.228124 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000031 (ops 150-154)
I20260812 06:18:44.228149 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000032 (ops 155-159)
I20260812 06:18:44.228178 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000033 (ops 160-164)
I20260812 06:18:44.228221 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000034 (ops 165-168)
I20260812 06:18:44.228250 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000035 (ops 169-173)
I20260812 06:18:44.228276 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000036 (ops 174-178)
I20260812 06:18:44.228302 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000037 (ops 179-183)
I20260812 06:18:44.228329 18605 log.cc:1079] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/657a548b1d374f3aa5a500dea754a1fe/wal-000000038 (ops 184-188)
I20260812 06:18:44.252754 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: LogGCOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.025s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:18:44.253185 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling UndoDeltaBlockGCOp(657a548b1d374f3aa5a500dea754a1fe): 483 bytes on disk
I20260812 06:18:44.253737 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: UndoDeltaBlockGCOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:18:44.254334 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=3.181125
I20260812 06:18:44.265738 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4594954,"delete_count":0,"lbm_write_time_us":4257,"lbm_writes_lt_1ms":115,"reinsert_count":0,"update_count":560}
I20260812 06:18:44.266172 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=2.188937
I20260812 06:18:44.276136 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.010s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3610355,"delete_count":0,"lbm_write_time_us":3204,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:18:44.276664 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe): perf score=1.000000
I20260812 06:18:44.443591 18401 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.471s	user 1.667s	sys 0.120s
I20260812 06:18:44.445484 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: MajorDeltaCompactionOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.169s	user 0.137s	sys 0.027s 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":206,"lbm_read_time_us":13351,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32860,"lbm_writes_lt_1ms":643,"mutex_wait_us":36,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2048,"thread_start_us":68,"threads_started":1,"update_count":3000}
I20260812 06:18:44.445942 18707 maintenance_manager.cc:419] P 15f3582c832c400e87a21a511bfcf28d: Scheduling FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe): perf score=14.095187
I20260812 06:18:44.470669 18401 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.027s	user 0.002s	sys 0.000s
I20260812 06:18:44.471278 18401 tablet_server.cc:179] TabletServer@127.17.248.65:0 shutting down...
I20260812 06:18:44.481403 18605 maintenance_manager.cc:643] P 15f3582c832c400e87a21a511bfcf28d: FlushDeltaMemStoresOp(657a548b1d374f3aa5a500dea754a1fe) complete. Timing: real 0.035s	user 0.032s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":15271,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:44.481937 18401 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:44.482283 18401 tablet_replica.cc:333] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d: stopping tablet replica
I20260812 06:18:44.482486 18401 raft_consensus.cc:2243] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:44.482689 18401 raft_consensus.cc:2272] T 657a548b1d374f3aa5a500dea754a1fe P 15f3582c832c400e87a21a511bfcf28d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:44.497067 18401 tablet_server.cc:196] TabletServer@127.17.248.65:0 shutdown complete.
I20260812 06:18:44.501400 18401 master.cc:562] Master@127.17.248.126:35737 shutting down...
I20260812 06:18:44.504492 18401 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:44.504645 18401 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:44.504717 18401 tablet_replica.cc:333] T 00000000000000000000000000000000 P 47f062bc60f84ee9ab91c2ac107daea2: stopping tablet replica
I20260812 06:18:44.516727 18401 master.cc:584] Master@127.17.248.126:35737 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (4893 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:44.588519 18401 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.17.248.126:38299
I20260812 06:18:44.588899 18401 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:44.590770 18774 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:44.590857 18777 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:44.590917 18781 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:44.591018 18401 server_base.cc:1061] running on GCE node
I20260812 06:18:44.591162 18401 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:44.591199 18401 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:44.591212 18401 hybrid_clock.cc:648] HybridClock initialized: now 1786515524591212 us; error 0 us; skew 500 ppm
I20260812 06:18:44.592005 18401 webserver.cc:533] Webserver started at http://127.17.248.126:41109/ using document root <none> and password file <none>
I20260812 06:18:44.592152 18401 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:44.592199 18401 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:44.592273 18401 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:44.592617 18401 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/master-0-root/instance:
uuid: "5a214e80300e4adcac7e7808e3fa52a2"
format_stamp: "Formatted at 2026-08-12 06:18:44 on dist-test-slave-gjw7"
I20260812 06:18:44.594075 18401 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:44.594928 18794 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:44.595166 18401 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:44.595237 18401 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/master-0-root
uuid: "5a214e80300e4adcac7e7808e3fa52a2"
format_stamp: "Formatted at 2026-08-12 06:18:44 on dist-test-slave-gjw7"
I20260812 06:18:44.595304 18401 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:44.610678 18401 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:44.611044 18401 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:44.615037 18401 rpc_server.cc:307] RPC server started. Bound to: 127.17.248.126:38299
I20260812 06:18:44.628486 18904 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.248.126:38299 every 8 connection(s)
I20260812 06:18:44.628947 18905 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:44.630718 18905 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2: Bootstrap starting.
I20260812 06:18:44.631459 18905 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:44.632362 18905 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2: No bootstrap required, opened a new log
I20260812 06:18:44.632725 18905 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5a214e80300e4adcac7e7808e3fa52a2" member_type: VOTER }
I20260812 06:18:44.632818 18905 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:44.632850 18905 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5a214e80300e4adcac7e7808e3fa52a2, State: Initialized, Role: FOLLOWER
I20260812 06:18:44.632982 18905 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [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: "5a214e80300e4adcac7e7808e3fa52a2" member_type: VOTER }
I20260812 06:18:44.633050 18905 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:44.633087 18905 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:44.633134 18905 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:44.633805 18905 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5a214e80300e4adcac7e7808e3fa52a2" member_type: VOTER }
I20260812 06:18:44.633925 18905 leader_election.cc:304] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [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: 5a214e80300e4adcac7e7808e3fa52a2; no voters: 
I20260812 06:18:44.634095 18905 leader_election.cc:290] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:44.634173 18908 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:44.634357 18908 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [term 1 LEADER]: Becoming Leader. State: Replica: 5a214e80300e4adcac7e7808e3fa52a2, State: Running, Role: LEADER
I20260812 06:18:44.634497 18905 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:44.634496 18908 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [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: "5a214e80300e4adcac7e7808e3fa52a2" member_type: VOTER }
I20260812 06:18:44.634904 18909 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5a214e80300e4adcac7e7808e3fa52a2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5a214e80300e4adcac7e7808e3fa52a2" member_type: VOTER } }
I20260812 06:18:44.634929 18913 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5a214e80300e4adcac7e7808e3fa52a2. Latest consensus state: current_term: 1 leader_uuid: "5a214e80300e4adcac7e7808e3fa52a2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5a214e80300e4adcac7e7808e3fa52a2" member_type: VOTER } }
I20260812 06:18:44.635051 18909 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:44.635072 18913 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:44.635654 18927 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:44.636525 18927 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:44.636729 18401 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:44.638242 18927 catalog_manager.cc:1383] Generated new cluster ID: 41da86101cf045888ddc7dc57c4afddd
I20260812 06:18:44.638302 18927 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:44.649942 18927 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:44.650496 18927 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:44.658972 18927 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2: Generated new TSK 0
I20260812 06:18:44.659168 18927 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:44.668826 18401 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:44.670584 18950 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:44.670663 18954 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:44.670769 18401 server_base.cc:1061] running on GCE node
W20260812 06:18:44.670821 18949 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:44.671010 18401 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:44.671052 18401 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:44.671072 18401 hybrid_clock.cc:648] HybridClock initialized: now 1786515524671071 us; error 0 us; skew 500 ppm
I20260812 06:18:44.671830 18401 webserver.cc:533] Webserver started at http://127.17.248.65:33299/ using document root <none> and password file <none>
I20260812 06:18:44.671978 18401 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:44.672027 18401 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:44.672101 18401 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:44.672462 18401 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/instance:
uuid: "aef57b45bc7d4d389b0cde1422613230"
format_stamp: "Formatted at 2026-08-12 06:18:44 on dist-test-slave-gjw7"
I20260812 06:18:44.673861 18401 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:44.674731 18960 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:44.674974 18401 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:44.675037 18401 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root
uuid: "aef57b45bc7d4d389b0cde1422613230"
format_stamp: "Formatted at 2026-08-12 06:18:44 on dist-test-slave-gjw7"
I20260812 06:18:44.675091 18401 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:44.679373 18401 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:44.679637 18401 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:44.679870 18401 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:44.680238 18401 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:44.680271 18401 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:44.680300 18401 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:44.680320 18401 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:44.684180 18401 rpc_server.cc:307] RPC server started. Bound to: 127.17.248.65:39853
I20260812 06:18:44.684201 19095 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.248.65:39853 every 8 connection(s)
I20260812 06:18:44.688488 19097 heartbeater.cc:344] Connected to a master server at 127.17.248.126:38299
I20260812 06:18:44.688580 19097 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:44.688786 19097 heartbeater.cc:507] Master 127.17.248.126:38299 requested a full tablet report, sending...
I20260812 06:18:44.689409 18835 ts_manager.cc:194] Registered new tserver with Master: aef57b45bc7d4d389b0cde1422613230 (127.17.248.65:39853)
I20260812 06:18:44.690012 18401 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.005468103s
I20260812 06:18:44.690095 18835 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46026
I20260812 06:18:44.696092 18835 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46030:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:44.703981 19025 tablet_service.cc:1511] Processing CreateTablet for tablet 9d8d57f3f98342e19e7efa4be0f6fb1e (DEFAULT_TABLE table=heavy-update-compaction-test [id=9fac304f9c9c453fa3e0372b7716665e]), partition=
I20260812 06:18:44.704242 19025 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 9d8d57f3f98342e19e7efa4be0f6fb1e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:44.706147 19121 tablet_bootstrap.cc:492] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Bootstrap starting.
I20260812 06:18:44.707032 19121 tablet_bootstrap.cc:654] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:44.707983 19121 tablet_bootstrap.cc:492] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: No bootstrap required, opened a new log
I20260812 06:18:44.708052 19121 ts_tablet_manager.cc:1403] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:44.708393 19121 raft_consensus.cc:359] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aef57b45bc7d4d389b0cde1422613230" member_type: VOTER last_known_addr { host: "127.17.248.65" port: 39853 } }
I20260812 06:18:44.708474 19121 raft_consensus.cc:385] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:44.708499 19121 raft_consensus.cc:740] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: aef57b45bc7d4d389b0cde1422613230, State: Initialized, Role: FOLLOWER
I20260812 06:18:44.708588 19121 consensus_queue.cc:260] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230 [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: "aef57b45bc7d4d389b0cde1422613230" member_type: VOTER last_known_addr { host: "127.17.248.65" port: 39853 } }
I20260812 06:18:44.708643 19121 raft_consensus.cc:399] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:44.708669 19121 raft_consensus.cc:493] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:44.708700 19121 raft_consensus.cc:3060] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:44.709422 19121 raft_consensus.cc:515] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aef57b45bc7d4d389b0cde1422613230" member_type: VOTER last_known_addr { host: "127.17.248.65" port: 39853 } }
I20260812 06:18:44.709558 19121 leader_election.cc:304] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230 [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: aef57b45bc7d4d389b0cde1422613230; no voters: 
I20260812 06:18:44.709749 19121 leader_election.cc:290] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:44.709875 19125 raft_consensus.cc:2804] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:44.710071 19121 ts_tablet_manager.cc:1434] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:44.710057 19125 raft_consensus.cc:697] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230 [term 1 LEADER]: Becoming Leader. State: Replica: aef57b45bc7d4d389b0cde1422613230, State: Running, Role: LEADER
I20260812 06:18:44.710119 19097 heartbeater.cc:499] Master 127.17.248.126:38299 was elected leader, sending a full tablet report...
I20260812 06:18:44.710238 19125 consensus_queue.cc:237] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230 [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: "aef57b45bc7d4d389b0cde1422613230" member_type: VOTER last_known_addr { host: "127.17.248.65" port: 39853 } }
I20260812 06:18:44.711479 18835 catalog_manager.cc:5719] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230 reported cstate change: term changed from 0 to 1, leader changed from <none> to aef57b45bc7d4d389b0cde1422613230 (127.17.248.65). New cstate: current_term: 1 leader_uuid: "aef57b45bc7d4d389b0cde1422613230" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aef57b45bc7d4d389b0cde1422613230" member_type: VOTER last_known_addr { host: "127.17.248.65" port: 39853 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:44.764328 18401 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.021s	sys 0.000s
I20260812 06:18:44.935079 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushMRSOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=23.023690
I20260812 06:18:45.075397 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushMRSOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.140s	user 0.105s	sys 0.032s Metrics: {"bytes_written":13210027,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":273,"dirs.run_wall_time_us":972,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36853,"lbm_writes_lt_1ms":879,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1610}
I20260812 06:18:45.076058 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:45.096891 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.021s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3610359,"delete_count":0,"lbm_write_time_us":4443,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:18:45.097431 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling LogGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e): free 20743880 bytes of WAL
I20260812 06:18:45.097632 18980 log_reader.cc:385] T 9d8d57f3f98342e19e7efa4be0f6fb1e: removed 2 log segments from log reader
I20260812 06:18:45.097692 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000001 (ops 1-6)
I20260812 06:18:45.097734 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000002 (ops 7-11)
I20260812 06:18:45.102356 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: LogGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:45.102676 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling UndoDeltaBlockGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e): 20513818 bytes on disk
I20260812 06:18:45.103106 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: UndoDeltaBlockGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:18:45.103519 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:45.114100 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3939,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:45.114473 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:45.281581 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.167s	user 0.111s	sys 0.049s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815786,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":609,"lbm_read_time_us":11123,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28957,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":304,"threads_started":5,"update_count":2500}
I20260812 06:18:45.282038 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=14.095187
I20260812 06:18:45.332600 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.050s	user 0.026s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19414,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:45.333135 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:45.342885 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3594,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.343353 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:45.500391 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.157s	user 0.120s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1104,"lbm_read_time_us":8657,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31651,"lbm_writes_lt_1ms":543,"mutex_wait_us":77,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2500}
I20260812 06:18:45.501556 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=11.118625
I20260812 06:18:45.537083 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.035s	user 0.021s	sys 0.013s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15337,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:45.537667 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:45.550665 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4805,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:45.553507 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:45.715178 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.161s	user 0.107s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713262,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":247,"lbm_read_time_us":11383,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25749,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:45.715900 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=14.095187
I20260812 06:18:45.764492 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.048s	user 0.021s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21482,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:45.765102 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:45.781977 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.017s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4170,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.782413 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:45.958308 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.176s	user 0.109s	sys 0.066s 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":240,"lbm_read_time_us":12313,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28770,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:18:45.958815 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=14.095187
I20260812 06:18:45.997973 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.039s	user 0.017s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17928,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:45.998528 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:46.014380 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.016s	user 0.013s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5928,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.015017 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:46.189324 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.174s	user 0.116s	sys 0.050s 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":120,"lbm_read_time_us":11754,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25122,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:18:46.189893 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=14.095187
I20260812 06:18:46.240391 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.050s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20375,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:46.240952 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:46.252063 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4152,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.252526 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushMRSOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:46.281472 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushMRSOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.029s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":1311,"drs_written":1,"lbm_read_time_us":34,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1288,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:46.282126 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling LogGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e): free 120553383 bytes of WAL
I20260812 06:18:46.282352 18980 log_reader.cc:385] T 9d8d57f3f98342e19e7efa4be0f6fb1e: removed 12 log segments from log reader
I20260812 06:18:46.282413 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000003 (ops 12-16)
I20260812 06:18:46.282449 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000004 (ops 17-20)
I20260812 06:18:46.282527 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000005 (ops 21-25)
I20260812 06:18:46.282582 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000006 (ops 26-30)
I20260812 06:18:46.282619 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000007 (ops 31-34)
I20260812 06:18:46.282655 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000008 (ops 35-39)
I20260812 06:18:46.282678 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000009 (ops 40-44)
I20260812 06:18:46.282698 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000010 (ops 45-49)
I20260812 06:18:46.282718 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000011 (ops 50-54)
I20260812 06:18:46.282755 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000012 (ops 55-59)
I20260812 06:18:46.282785 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000013 (ops 60-64)
I20260812 06:18:46.282814 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000014 (ops 65-69)
I20260812 06:18:46.306201 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: LogGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.024s	user 0.001s	sys 0.022s Metrics: {}
I20260812 06:18:46.306751 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling UndoDeltaBlockGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e): 463 bytes on disk
I20260812 06:18:46.307277 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: UndoDeltaBlockGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:18:46.307845 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=3.181125
I20260812 06:18:46.325976 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.018s	user 0.009s	sys 0.008s Metrics: {"bytes_written":5251341,"delete_count":0,"lbm_write_time_us":7245,"lbm_writes_lt_1ms":131,"reinsert_count":0,"update_count":640}
I20260812 06:18:46.326455 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.196750
I20260812 06:18:46.336225 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":3743,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:18:46.336675 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:46.580555 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.244s	user 0.169s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020716,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":222,"lbm_read_time_us":16002,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43717,"lbm_writes_lt_1ms":743,"mutex_wait_us":298,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11648,"thread_start_us":101,"threads_started":1,"update_count":3500}
I20260812 06:18:46.581251 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=18.063937
I20260812 06:18:46.645049 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.064s	user 0.010s	sys 0.037s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":23568,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:46.645550 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:46.655431 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3647,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.656014 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:46.833654 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.177s	user 0.108s	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":540,"lbm_read_time_us":13278,"lbm_reads_lt_1ms":672,"lbm_write_time_us":28406,"lbm_writes_lt_1ms":643,"mutex_wait_us":314,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":3000}
I20260812 06:18:46.834290 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=14.095187
I20260812 06:18:46.868928 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.034s	user 0.020s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":15242,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:46.869405 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:46.881834 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4226,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.882339 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:47.039054 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.157s	user 0.098s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":193,"lbm_read_time_us":10395,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26186,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:18:47.039562 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=14.095187
I20260812 06:18:47.097820 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.058s	user 0.025s	sys 0.026s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18115,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:47.098371 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:47.113427 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5710,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.113910 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:47.287815 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.174s	user 0.120s	sys 0.049s 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":182,"lbm_read_time_us":11483,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28629,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:18:47.288388 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=14.095187
I20260812 06:18:47.349831 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.061s	user 0.026s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17287,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:47.350435 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:47.365427 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.015s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5606,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.365841 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:47.535151 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.169s	user 0.100s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":607,"lbm_read_time_us":11154,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25146,"lbm_writes_lt_1ms":543,"mutex_wait_us":304,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:18:47.535694 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=14.095187
I20260812 06:18:47.580785 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.045s	user 0.018s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16461,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:47.581282 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:47.598537 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.017s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3604,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.599009 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushMRSOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:47.634001 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushMRSOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.035s	user 0.025s	sys 0.002s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":1240,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1335,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:47.634644 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling LogGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e): free 112239324 bytes of WAL
I20260812 06:18:47.634845 18980 log_reader.cc:385] T 9d8d57f3f98342e19e7efa4be0f6fb1e: removed 11 log segments from log reader
I20260812 06:18:47.634891 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000015 (ops 70-74)
I20260812 06:18:47.634919 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000016 (ops 75-79)
I20260812 06:18:47.634951 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000017 (ops 80-84)
I20260812 06:18:47.634984 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000018 (ops 85-89)
I20260812 06:18:47.635015 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000019 (ops 90-94)
I20260812 06:18:47.635047 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000020 (ops 95-98)
I20260812 06:18:47.635079 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000021 (ops 99-103)
I20260812 06:18:47.635110 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000022 (ops 104-108)
I20260812 06:18:47.635141 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000023 (ops 109-113)
I20260812 06:18:47.635172 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000024 (ops 114-118)
I20260812 06:18:47.635203 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000025 (ops 119-123)
I20260812 06:18:47.654469 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: LogGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.020s	user 0.002s	sys 0.017s Metrics: {}
I20260812 06:18:47.654847 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:47.667547 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4184708,"delete_count":0,"lbm_write_time_us":4946,"lbm_writes_lt_1ms":105,"reinsert_count":0,"update_count":510}
I20260812 06:18:47.668066 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling LogGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e): free 12017932 bytes of WAL
I20260812 06:18:47.668324 18980 log_reader.cc:385] T 9d8d57f3f98342e19e7efa4be0f6fb1e: removed 1 log segments from log reader
I20260812 06:18:47.668380 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000026 (ops 124-128)
I20260812 06:18:47.670295 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: LogGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:47.670588 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling UndoDeltaBlockGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e): 447 bytes on disk
I20260812 06:18:47.671033 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: UndoDeltaBlockGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:18:47.671569 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:47.868989 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.197s	user 0.124s	sys 0.069s Metrics: {"cfile_cache_miss":635,"cfile_cache_miss_bytes":29000263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":157,"lbm_read_time_us":11968,"lbm_reads_lt_1ms":667,"lbm_write_time_us":31099,"lbm_writes_lt_1ms":645,"mutex_wait_us":47,"peak_mem_usage":75624542,"reinsert_count":0,"spinlock_wait_cycles":12544,"thread_start_us":71,"threads_started":1,"update_count":3010}
I20260812 06:18:47.869534 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=18.063937
I20260812 06:18:47.922801 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.053s	user 0.036s	sys 0.015s Metrics: {"bytes_written":20430272,"delete_count":0,"lbm_write_time_us":23561,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2490}
I20260812 06:18:47.923295 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:48.081164 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.158s	user 0.097s	sys 0.061s Metrics: {"cfile_cache_miss":529,"cfile_cache_miss_bytes":24733523,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":159,"lbm_read_time_us":11713,"lbm_reads_lt_1ms":561,"lbm_write_time_us":25252,"lbm_writes_lt_1ms":541,"mutex_wait_us":54,"peak_mem_usage":61993446,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2490}
I20260812 06:18:48.084158 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=14.095187
I20260812 06:18:48.136902 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.053s	user 0.031s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18552,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:48.137524 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:48.152637 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5772,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.153168 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:48.314910 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.162s	user 0.132s	sys 0.024s 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":590,"lbm_read_time_us":11304,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24778,"lbm_writes_lt_1ms":543,"mutex_wait_us":288,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:48.315423 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=14.095187
I20260812 06:18:48.368280 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.053s	user 0.022s	sys 0.024s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21154,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:48.368774 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:48.390518 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.022s	user 0.014s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5405,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.391103 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:48.572484 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.181s	user 0.097s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":581,"lbm_read_time_us":12504,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26522,"lbm_writes_lt_1ms":543,"mutex_wait_us":267,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:18:48.572996 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=14.095187
I20260812 06:18:48.620682 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.047s	user 0.018s	sys 0.021s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18663,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:48.621160 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:48.631548 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.010s	user 0.002s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3589,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.632107 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:48.802198 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.170s	user 0.111s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":606,"lbm_read_time_us":10337,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27395,"lbm_writes_lt_1ms":543,"mutex_wait_us":59,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:48.802727 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=14.095187
I20260812 06:18:48.848483 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.046s	user 0.032s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18646,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:48.849045 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:48.859432 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3681,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.860029 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:49.001457 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.140s	user 0.119s	sys 0.018s 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":557,"lbm_read_time_us":10799,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26072,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":35328,"update_count":2500}
I20260812 06:18:49.002084 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=11.118625
I20260812 06:18:49.040349 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.038s	user 0.026s	sys 0.009s Metrics: {"bytes_written":13168992,"delete_count":0,"lbm_write_time_us":15674,"lbm_writes_lt_1ms":324,"reinsert_count":0,"update_count":1605}
I20260812 06:18:49.040912 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:49.056139 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.015s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3651384,"delete_count":0,"lbm_write_time_us":3553,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:18:49.056602 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:49.065377 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3160,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:49.065776 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushMRSOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:49.092989 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushMRSOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.027s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":195,"dirs.run_wall_time_us":1600,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1275,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:49.093639 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling LogGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e): free 120553643 bytes of WAL
I20260812 06:18:49.093849 18980 log_reader.cc:385] T 9d8d57f3f98342e19e7efa4be0f6fb1e: removed 12 log segments from log reader
I20260812 06:18:49.093896 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000027 (ops 129-133)
I20260812 06:18:49.093924 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000028 (ops 134-138)
I20260812 06:18:49.093956 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000029 (ops 139-143)
I20260812 06:18:49.093990 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000030 (ops 144-148)
I20260812 06:18:49.094022 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000031 (ops 149-152)
I20260812 06:18:49.094053 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000032 (ops 153-157)
I20260812 06:18:49.094085 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000033 (ops 158-162)
I20260812 06:18:49.094117 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000034 (ops 163-167)
I20260812 06:18:49.094149 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000035 (ops 168-172)
I20260812 06:18:49.094180 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000036 (ops 173-176)
I20260812 06:18:49.094213 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000037 (ops 177-181)
I20260812 06:18:49.094244 18980 log.cc:1079] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: Deleting log segment in path: /tmp/dist-test-taskUo4c40/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515519685578-18401-0/minicluster-data/ts-0-root/wals/9d8d57f3f98342e19e7efa4be0f6fb1e/wal-000000038 (ops 182-186)
I20260812 06:18:49.115015 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: LogGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.021s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:18:49.115407 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=3.181125
I20260812 06:18:49.130735 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.015s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":3961,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:49.131187 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:49.148449 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.017s	user 0.007s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3313,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:49.149029 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:49.354979 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.206s	user 0.106s	sys 0.100s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020828,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":389,"lbm_read_time_us":13939,"lbm_reads_lt_1ms":775,"lbm_write_time_us":34544,"lbm_writes_lt_1ms":743,"mutex_wait_us":34,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":69,"threads_started":1,"update_count":3500}
I20260812 06:18:49.355556 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=14.095187
I20260812 06:18:49.386250 18401 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.622s	user 1.717s	sys 0.168s
I20260812 06:18:49.396621 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.041s	user 0.028s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18401,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:49.397061 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling UndoDeltaBlockGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e): 482 bytes on disk
I20260812 06:18:49.397466 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: UndoDeltaBlockGCOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:18:49.398038 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=2.188937
I20260812 06:18:49.410072 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: FlushDeltaMemStoresOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4667,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.410473 19102 maintenance_manager.cc:419] P aef57b45bc7d4d389b0cde1422613230: Scheduling MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e): perf score=1.000000
I20260812 06:18:49.426625 18401 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.040s	user 0.001s	sys 0.001s
I20260812 06:18:49.427099 18401 tablet_server.cc:179] TabletServer@127.17.248.65:0 shutting down...
I20260812 06:18:49.544821 18980 maintenance_manager.cc:643] P aef57b45bc7d4d389b0cde1422613230: MajorDeltaCompactionOp(9d8d57f3f98342e19e7efa4be0f6fb1e) complete. Timing: real 0.134s	user 0.107s	sys 0.027s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4303385,"cfile_cache_miss":502,"cfile_cache_miss_bytes":20512298,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":258,"lbm_read_time_us":7223,"lbm_reads_lt_1ms":518,"lbm_write_time_us":21391,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:49.545588 18401 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:49.545862 18401 tablet_replica.cc:333] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230: stopping tablet replica
I20260812 06:18:49.545972 18401 raft_consensus.cc:2243] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:49.546129 18401 raft_consensus.cc:2272] T 9d8d57f3f98342e19e7efa4be0f6fb1e P aef57b45bc7d4d389b0cde1422613230 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:49.549312 18401 tablet_server.cc:196] TabletServer@127.17.248.65:0 shutdown complete.
I20260812 06:18:49.588963 18401 master.cc:562] Master@127.17.248.126:38299 shutting down...
I20260812 06:18:49.591961 18401 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:49.592118 18401 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:49.592166 18401 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5a214e80300e4adcac7e7808e3fa52a2: stopping tablet replica
I20260812 06:18:49.604202 18401 master.cc:584] Master@127.17.248.126:38299 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5087 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9981 ms total)

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