[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:40.535435 27526 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.225.190:34503
I20260812 06:17:40.536432 27526 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:40.537039 27526 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:40.543605 27531 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:40.543617 27532 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:40.543882 27534 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:40.543785 27526 server_base.cc:1061] running on GCE node
I20260812 06:17:40.544324 27526 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:40.544446 27526 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:40.544507 27526 hybrid_clock.cc:648] HybridClock initialized: now 1786515460544504 us; error 0 us; skew 500 ppm
I20260812 06:17:40.546316 27526 webserver.cc:533] Webserver started at http://127.26.225.190:34593/ using document root <none> and password file <none>
I20260812 06:17:40.546846 27526 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:40.546932 27526 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:40.547183 27526 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:40.548821 27526 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/master-0-root/instance:
uuid: "96b85b59ce3646ccbdbaeee84826b9f4"
format_stamp: "Formatted at 2026-08-12 06:17:40 on dist-test-slave-9gcw"
I20260812 06:17:40.552500 27526 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:17:40.554610 27540 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:40.555585 27526 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:40.555717 27526 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/master-0-root
uuid: "96b85b59ce3646ccbdbaeee84826b9f4"
format_stamp: "Formatted at 2026-08-12 06:17:40 on dist-test-slave-9gcw"
I20260812 06:17:40.555822 27526 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:40.577638 27526 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:40.578387 27526 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:40.578583 27526 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:40.586661 27526 rpc_server.cc:307] RPC server started. Bound to: 127.26.225.190:34503
I20260812 06:17:40.586674 27599 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.225.190:34503 every 8 connection(s)
I20260812 06:17:40.588979 27600 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:40.594383 27600 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4: Bootstrap starting.
I20260812 06:17:40.596726 27600 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:40.597652 27600 log.cc:826] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:40.599350 27600 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4: No bootstrap required, opened a new log
I20260812 06:17:40.602240 27600 raft_consensus.cc:359] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "96b85b59ce3646ccbdbaeee84826b9f4" member_type: VOTER }
I20260812 06:17:40.602411 27600 raft_consensus.cc:385] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:40.602451 27600 raft_consensus.cc:740] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 96b85b59ce3646ccbdbaeee84826b9f4, State: Initialized, Role: FOLLOWER
I20260812 06:17:40.603005 27600 consensus_queue.cc:260] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [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: "96b85b59ce3646ccbdbaeee84826b9f4" member_type: VOTER }
I20260812 06:17:40.603137 27600 raft_consensus.cc:399] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:40.603178 27600 raft_consensus.cc:493] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:40.603266 27600 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:40.604046 27600 raft_consensus.cc:515] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "96b85b59ce3646ccbdbaeee84826b9f4" member_type: VOTER }
I20260812 06:17:40.604432 27600 leader_election.cc:304] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [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: 96b85b59ce3646ccbdbaeee84826b9f4; no voters: 
I20260812 06:17:40.604699 27600 leader_election.cc:290] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:40.604878 27603 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:40.605134 27603 raft_consensus.cc:697] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [term 1 LEADER]: Becoming Leader. State: Replica: 96b85b59ce3646ccbdbaeee84826b9f4, State: Running, Role: LEADER
I20260812 06:17:40.605623 27603 consensus_queue.cc:237] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [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: "96b85b59ce3646ccbdbaeee84826b9f4" member_type: VOTER }
I20260812 06:17:40.605789 27600 sys_catalog.cc:565] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:40.607559 27604 sys_catalog.cc:455] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "96b85b59ce3646ccbdbaeee84826b9f4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "96b85b59ce3646ccbdbaeee84826b9f4" member_type: VOTER } }
I20260812 06:17:40.607507 27605 sys_catalog.cc:455] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 96b85b59ce3646ccbdbaeee84826b9f4. Latest consensus state: current_term: 1 leader_uuid: "96b85b59ce3646ccbdbaeee84826b9f4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "96b85b59ce3646ccbdbaeee84826b9f4" member_type: VOTER } }
I20260812 06:17:40.607648 27605 sys_catalog.cc:458] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:40.607648 27604 sys_catalog.cc:458] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:40.608162 27526 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:40.608474 27617 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:40.610702 27617 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:40.615465 27617 catalog_manager.cc:1383] Generated new cluster ID: bc3689c89bb2454db5e6b6c452276296
I20260812 06:17:40.615542 27617 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:40.625586 27617 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:40.626742 27617 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:40.634873 27617 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4: Generated new TSK 0
I20260812 06:17:40.635689 27617 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:40.640872 27526 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:40.644032 27626 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:40.644101 27629 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:40.644054 27627 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:40.644367 27526 server_base.cc:1061] running on GCE node
I20260812 06:17:40.644637 27526 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:40.644701 27526 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:40.644723 27526 hybrid_clock.cc:648] HybridClock initialized: now 1786515460644723 us; error 0 us; skew 500 ppm
I20260812 06:17:40.645782 27526 webserver.cc:533] Webserver started at http://127.26.225.129:45329/ using document root <none> and password file <none>
I20260812 06:17:40.645972 27526 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:40.646050 27526 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:40.646131 27526 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:40.646600 27526 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/instance:
uuid: "6cb6796743d7413db974777f33c2dcd1"
format_stamp: "Formatted at 2026-08-12 06:17:40 on dist-test-slave-9gcw"
I20260812 06:17:40.648564 27526 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:17:40.649803 27635 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:40.650107 27526 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:40.650174 27526 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root
uuid: "6cb6796743d7413db974777f33c2dcd1"
format_stamp: "Formatted at 2026-08-12 06:17:40 on dist-test-slave-9gcw"
I20260812 06:17:40.650270 27526 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:40.678574 27526 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:40.679129 27526 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:40.679641 27526 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:40.680584 27526 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:40.680636 27526 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:40.680706 27526 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:40.680752 27526 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:40.687683 27526 rpc_server.cc:307] RPC server started. Bound to: 127.26.225.129:44835
I20260812 06:17:40.687717 27709 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.225.129:44835 every 8 connection(s)
I20260812 06:17:40.697960 27710 heartbeater.cc:344] Connected to a master server at 127.26.225.190:34503
I20260812 06:17:40.698208 27710 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:40.698659 27710 heartbeater.cc:507] Master 127.26.225.190:34503 requested a full tablet report, sending...
I20260812 06:17:40.700021 27559 ts_manager.cc:194] Registered new tserver with Master: 6cb6796743d7413db974777f33c2dcd1 (127.26.225.129:44835)
I20260812 06:17:40.700259 27526 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01190803s
I20260812 06:17:40.701306 27559 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:42308
I20260812 06:17:40.710155 27559 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:42322:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:40.724555 27663 tablet_service.cc:1511] Processing CreateTablet for tablet 18000291c01a4809a8f9b2d9e85dd7eb (DEFAULT_TABLE table=heavy-update-compaction-test [id=92f480f9c5bc4706b947dc03155d6640]), partition=
I20260812 06:17:40.725070 27663 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 18000291c01a4809a8f9b2d9e85dd7eb. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:40.727265 27727 tablet_bootstrap.cc:492] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Bootstrap starting.
I20260812 06:17:40.728366 27727 tablet_bootstrap.cc:654] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:40.729717 27727 tablet_bootstrap.cc:492] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: No bootstrap required, opened a new log
I20260812 06:17:40.729830 27727 ts_tablet_manager.cc:1403] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:40.730351 27727 raft_consensus.cc:359] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6cb6796743d7413db974777f33c2dcd1" member_type: VOTER last_known_addr { host: "127.26.225.129" port: 44835 } }
I20260812 06:17:40.730479 27727 raft_consensus.cc:385] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:40.730510 27727 raft_consensus.cc:740] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6cb6796743d7413db974777f33c2dcd1, State: Initialized, Role: FOLLOWER
I20260812 06:17:40.730679 27727 consensus_queue.cc:260] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1 [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: "6cb6796743d7413db974777f33c2dcd1" member_type: VOTER last_known_addr { host: "127.26.225.129" port: 44835 } }
I20260812 06:17:40.730778 27727 raft_consensus.cc:399] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:40.730821 27727 raft_consensus.cc:493] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:40.730872 27727 raft_consensus.cc:3060] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:40.731828 27727 raft_consensus.cc:515] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6cb6796743d7413db974777f33c2dcd1" member_type: VOTER last_known_addr { host: "127.26.225.129" port: 44835 } }
I20260812 06:17:40.731971 27727 leader_election.cc:304] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1 [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: 6cb6796743d7413db974777f33c2dcd1; no voters: 
I20260812 06:17:40.732182 27727 leader_election.cc:290] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:40.732563 27727 ts_tablet_manager.cc:1434] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:40.732720 27730 raft_consensus.cc:2804] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:40.732961 27730 raft_consensus.cc:697] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1 [term 1 LEADER]: Becoming Leader. State: Replica: 6cb6796743d7413db974777f33c2dcd1, State: Running, Role: LEADER
I20260812 06:17:40.732985 27710 heartbeater.cc:499] Master 127.26.225.190:34503 was elected leader, sending a full tablet report...
I20260812 06:17:40.733510 27730 consensus_queue.cc:237] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1 [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: "6cb6796743d7413db974777f33c2dcd1" member_type: VOTER last_known_addr { host: "127.26.225.129" port: 44835 } }
I20260812 06:17:40.736249 27559 catalog_manager.cc:5719] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1 reported cstate change: term changed from 0 to 1, leader changed from <none> to 6cb6796743d7413db974777f33c2dcd1 (127.26.225.129). New cstate: current_term: 1 leader_uuid: "6cb6796743d7413db974777f33c2dcd1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6cb6796743d7413db974777f33c2dcd1" member_type: VOTER last_known_addr { host: "127.26.225.129" port: 44835 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:40.802958 27526 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.020s	sys 0.007s
I20260812 06:17:40.938863 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushMRSOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=19.054940
I20260812 06:17:41.093647 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushMRSOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.154s	user 0.108s	sys 0.045s Metrics: {"bytes_written":8779422,"cfile_init":1,"compiler_manager_pool.queue_time_us":195,"delete_count":0,"dirs.queue_time_us":44,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":893,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38913,"lbm_writes_lt_1ms":671,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":278784,"thread_start_us":128,"threads_started":1,"update_count":1070}
I20260812 06:17:41.094755 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling LogGCOp(18000291c01a4809a8f9b2d9e85dd7eb): free 20743831 bytes of WAL
I20260812 06:17:41.095078 27640 log_reader.cc:385] T 18000291c01a4809a8f9b2d9e85dd7eb: removed 2 log segments from log reader
I20260812 06:17:41.095157 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000001 (ops 1-6)
I20260812 06:17:41.095244 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000002 (ops 7-11)
I20260812 06:17:41.100368 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: LogGCOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:41.100871 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:41.115355 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3528305,"delete_count":0,"lbm_write_time_us":4808,"lbm_writes_lt_1ms":89,"reinsert_count":0,"update_count":430}
I20260812 06:17:41.116030 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling UndoDeltaBlockGCOp(18000291c01a4809a8f9b2d9e85dd7eb): 16411393 bytes on disk
I20260812 06:17:41.116767 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: UndoDeltaBlockGCOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:17:41.117432 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:41.238247 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.121s	user 0.099s	sys 0.008s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569855,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":858,"lbm_read_time_us":6348,"lbm_reads_lt_1ms":360,"lbm_write_time_us":20549,"lbm_writes_lt_1ms":343,"mutex_wait_us":23,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":11008,"thread_start_us":269,"threads_started":5,"update_count":1500}
I20260812 06:17:41.238967 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=10.126437
I20260812 06:17:41.273934 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.035s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14481,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:41.274452 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:41.388456 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.114s	user 0.085s	sys 0.028s 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":1276,"lbm_read_time_us":8542,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21343,"lbm_writes_lt_1ms":343,"mutex_wait_us":329,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":1500}
I20260812 06:17:41.389128 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=10.126437
I20260812 06:17:41.427670 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.038s	user 0.026s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16797,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:41.428181 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:41.446432 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.018s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5525,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.446928 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:41.567692 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.121s	user 0.081s	sys 0.038s 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":2024,"lbm_read_time_us":7057,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24276,"lbm_writes_lt_1ms":443,"mutex_wait_us":776,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:41.568221 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=10.126437
I20260812 06:17:41.602874 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.034s	user 0.024s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14918,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:41.603546 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:41.623600 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.020s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6236,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.624112 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:41.743871 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.120s	user 0.100s	sys 0.019s 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":834,"lbm_read_time_us":7088,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24369,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:17:41.744413 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=11.118625
I20260812 06:17:41.777483 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.033s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15341,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:41.778087 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:41.792718 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4951,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:41.793226 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:41.924314 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.131s	user 0.101s	sys 0.028s 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":1716,"lbm_read_time_us":10203,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24648,"lbm_writes_lt_1ms":443,"mutex_wait_us":1341,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:17:41.925685 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=10.126437
I20260812 06:17:41.970184 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.044s	user 0.015s	sys 0.028s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16030,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:41.970793 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:41.981698 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4204,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.982208 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:42.130867 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.148s	user 0.100s	sys 0.048s 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":196,"lbm_read_time_us":11841,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22722,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:17:42.131348 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=10.126437
I20260812 06:17:42.176510 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.045s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16722,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:42.176966 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:42.188150 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4037,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.188804 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:42.313781 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.125s	user 0.097s	sys 0.027s 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":293,"lbm_read_time_us":9385,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22374,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":27776,"update_count":2000}
I20260812 06:17:42.314396 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=10.126437
I20260812 06:17:42.354038 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.040s	user 0.031s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16896,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":1500}
I20260812 06:17:42.354519 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:42.369338 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5545,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.369874 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushMRSOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:42.395953 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushMRSOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.026s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1518,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1406,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:42.396739 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling LogGCOp(18000291c01a4809a8f9b2d9e85dd7eb): free 121006483 bytes of WAL
I20260812 06:17:42.396996 27640 log_reader.cc:385] T 18000291c01a4809a8f9b2d9e85dd7eb: removed 12 log segments from log reader
I20260812 06:17:42.397042 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000003 (ops 12-16)
I20260812 06:17:42.397073 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000004 (ops 17-20)
I20260812 06:17:42.397090 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000005 (ops 21-25)
I20260812 06:17:42.397173 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000006 (ops 26-30)
I20260812 06:17:42.397217 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000007 (ops 31-35)
I20260812 06:17:42.397243 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000008 (ops 36-40)
I20260812 06:17:42.397296 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000009 (ops 41-45)
I20260812 06:17:42.397333 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000010 (ops 46-50)
I20260812 06:17:42.397375 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000011 (ops 51-55)
I20260812 06:17:42.397404 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000012 (ops 56-60)
I20260812 06:17:42.397442 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000013 (ops 61-65)
I20260812 06:17:42.397464 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000014 (ops 66-70)
I20260812 06:17:42.425277 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: LogGCOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.028s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:17:42.426074 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling UndoDeltaBlockGCOp(18000291c01a4809a8f9b2d9e85dd7eb): 483 bytes on disk
I20260812 06:17:42.426617 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: UndoDeltaBlockGCOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:17:42.427096 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=4.173312
I20260812 06:17:42.444306 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":5743633,"delete_count":0,"lbm_write_time_us":6968,"lbm_writes_lt_1ms":143,"reinsert_count":0,"update_count":700}
I20260812 06:17:42.444815 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.196750
I20260812 06:17:42.457382 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.012s	user 0.012s	sys 0.000s Metrics: {"bytes_written":2461654,"delete_count":0,"lbm_write_time_us":3878,"lbm_writes_lt_1ms":63,"reinsert_count":0,"update_count":300}
I20260812 06:17:42.457933 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:42.620857 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.163s	user 0.150s	sys 0.011s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":917,"lbm_read_time_us":12540,"lbm_reads_lt_1ms":666,"lbm_write_time_us":31457,"lbm_writes_lt_1ms":643,"mutex_wait_us":77,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:17:42.621491 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=14.095187
I20260812 06:17:42.670058 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.047s	user 0.032s	sys 0.014s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20373,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.670641 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:42.683109 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.012s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4142,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.683701 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:42.830390 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.146s	user 0.124s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":273,"lbm_read_time_us":9185,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30383,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:17:42.830945 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=11.118625
I20260812 06:17:42.880035 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.049s	user 0.019s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19678,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:42.880529 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:42.890992 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4046,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.891479 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:42.901015 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3538,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:42.901563 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:43.060384 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.159s	user 0.101s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":353,"lbm_read_time_us":11889,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30761,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:43.061601 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=12.110812
I20260812 06:17:43.103013 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.041s	user 0.023s	sys 0.016s Metrics: {"bytes_written":13538209,"delete_count":0,"lbm_write_time_us":17856,"lbm_writes_lt_1ms":333,"reinsert_count":0,"update_count":1650}
I20260812 06:17:43.103675 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.196750
I20260812 06:17:43.117112 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.013s	user 0.008s	sys 0.000s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":3608,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:17:43.117842 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:43.263314 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.145s	user 0.087s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672242,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":222,"lbm_read_time_us":8436,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23563,"lbm_writes_lt_1ms":443,"mutex_wait_us":77,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2000}
I20260812 06:17:43.264070 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=14.095187
I20260812 06:17:43.317795 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.054s	user 0.042s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23454,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:43.318400 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:43.345350 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.027s	user 0.006s	sys 0.021s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6937,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.345890 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:43.531728 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.186s	user 0.129s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":181,"lbm_read_time_us":12219,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31787,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:43.532748 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=14.095187
I20260812 06:17:43.582298 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.049s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22704,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:43.582924 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:43.594679 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4493,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.595286 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:43.781651 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.186s	user 0.127s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":348,"lbm_read_time_us":11760,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29298,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:43.782429 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=14.095187
I20260812 06:17:43.833964 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.051s	user 0.015s	sys 0.032s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21650,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:43.834419 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:43.845804 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4065,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.846328 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushMRSOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:43.877935 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushMRSOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.031s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1515,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1456,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:43.878613 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling LogGCOp(18000291c01a4809a8f9b2d9e85dd7eb): free 124257260 bytes of WAL
I20260812 06:17:43.878845 27640 log_reader.cc:385] T 18000291c01a4809a8f9b2d9e85dd7eb: removed 12 log segments from log reader
I20260812 06:17:43.878906 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000015 (ops 71-75)
I20260812 06:17:43.878962 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000016 (ops 76-80)
I20260812 06:17:43.879021 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000017 (ops 81-84)
I20260812 06:17:43.879061 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000018 (ops 85-89)
I20260812 06:17:43.879098 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000019 (ops 90-94)
I20260812 06:17:43.879136 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000020 (ops 95-99)
I20260812 06:17:43.879172 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000021 (ops 100-104)
I20260812 06:17:43.879209 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000022 (ops 105-109)
I20260812 06:17:43.879246 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000023 (ops 110-114)
I20260812 06:17:43.879283 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000024 (ops 115-119)
I20260812 06:17:43.879320 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000025 (ops 120-124)
I20260812 06:17:43.879357 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000026 (ops 125-129)
I20260812 06:17:43.907439 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: LogGCOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:43.907941 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=3.181125
I20260812 06:17:43.930773 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.023s	user 0.019s	sys 0.001s Metrics: {"bytes_written":4800077,"delete_count":0,"lbm_write_time_us":8284,"lbm_writes_lt_1ms":120,"reinsert_count":0,"update_count":585}
I20260812 06:17:43.931248 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling LogGCOp(18000291c01a4809a8f9b2d9e85dd7eb): free 12017954 bytes of WAL
I20260812 06:17:43.931444 27640 log_reader.cc:385] T 18000291c01a4809a8f9b2d9e85dd7eb: removed 1 log segments from log reader
I20260812 06:17:43.931490 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000027 (ops 130-134)
I20260812 06:17:43.934473 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: LogGCOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:43.934782 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling UndoDeltaBlockGCOp(18000291c01a4809a8f9b2d9e85dd7eb): 472 bytes on disk
I20260812 06:17:43.935204 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: UndoDeltaBlockGCOp(18000291c01a4809a8f9b2d9e85dd7eb) 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:17:43.935772 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:43.949867 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3405230,"delete_count":0,"lbm_write_time_us":5358,"lbm_writes_lt_1ms":86,"reinsert_count":0,"update_count":415}
I20260812 06:17:43.950451 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:44.179276 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.229s	user 0.156s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979742,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":611,"lbm_read_time_us":16220,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40536,"lbm_writes_lt_1ms":743,"mutex_wait_us":294,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10752,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:17:44.180040 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=14.095187
I20260812 06:17:44.231910 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.052s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22610,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:44.232755 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:44.254859 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.022s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7082,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.255363 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:44.435752 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.180s	user 0.123s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":80,"lbm_read_time_us":12205,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29912,"lbm_writes_lt_1ms":543,"mutex_wait_us":65,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:44.436400 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=15.087375
I20260812 06:17:44.507417 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.071s	user 0.036s	sys 0.028s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":25312,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:44.508067 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=5.165500
I20260812 06:17:44.526391 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.018s	user 0.013s	sys 0.004s Metrics: {"bytes_written":6892305,"delete_count":0,"lbm_write_time_us":7641,"lbm_writes_lt_1ms":171,"reinsert_count":0,"update_count":840}
I20260812 06:17:44.527293 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:44.725921 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.198s	user 0.143s	sys 0.055s Metrics: {"cfile_cache_miss":610,"cfile_cache_miss_bytes":27974569,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":195,"lbm_read_time_us":16140,"lbm_reads_lt_1ms":646,"lbm_write_time_us":32235,"lbm_writes_lt_1ms":621,"mutex_wait_us":27,"peak_mem_usage":72558934,"reinsert_count":0,"spinlock_wait_cycles":33280,"update_count":2890}
I20260812 06:17:44.726779 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=15.087375
I20260812 06:17:44.785120 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.058s	user 0.025s	sys 0.028s Metrics: {"bytes_written":17312442,"delete_count":0,"lbm_write_time_us":27640,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":422,"reinsert_count":0,"update_count":2110}
I20260812 06:17:44.785688 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:44.803017 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.017s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6399,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.803530 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:44.980528 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.177s	user 0.130s	sys 0.044s Metrics: {"cfile_cache_miss":554,"cfile_cache_miss_bytes":25677229,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":839,"lbm_read_time_us":13019,"lbm_reads_lt_1ms":586,"lbm_write_time_us":30176,"lbm_writes_lt_1ms":565,"mutex_wait_us":58,"peak_mem_usage":65059054,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2610}
I20260812 06:17:44.981201 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=14.095187
I20260812 06:17:45.034978 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.054s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22465,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:45.035630 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:45.046474 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4129,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.046980 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:45.221226 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.174s	user 0.128s	sys 0.038s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1296,"lbm_read_time_us":12066,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27369,"lbm_writes_lt_1ms":543,"mutex_wait_us":417,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:45.221738 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=14.095187
I20260812 06:17:45.285807 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.064s	user 0.043s	sys 0.021s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":25323,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:45.286520 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:45.297709 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4337,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.298194 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushMRSOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:45.336985 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushMRSOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.039s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":315,"dirs.run_wall_time_us":1988,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1360,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:45.337911 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling LogGCOp(18000291c01a4809a8f9b2d9e85dd7eb): free 108535700 bytes of WAL
I20260812 06:17:45.338171 27640 log_reader.cc:385] T 18000291c01a4809a8f9b2d9e85dd7eb: removed 11 log segments from log reader
I20260812 06:17:45.338246 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000028 (ops 135-139)
I20260812 06:17:45.338338 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000029 (ops 140-144)
I20260812 06:17:45.338392 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000030 (ops 145-148)
I20260812 06:17:45.338433 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000031 (ops 149-153)
I20260812 06:17:45.338469 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000032 (ops 154-158)
I20260812 06:17:45.338505 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000033 (ops 159-163)
I20260812 06:17:45.338542 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000034 (ops 164-168)
I20260812 06:17:45.338579 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000035 (ops 169-172)
I20260812 06:17:45.338616 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000036 (ops 173-177)
I20260812 06:17:45.338652 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000037 (ops 178-182)
I20260812 06:17:45.338689 27640 log.cc:1079] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/18000291c01a4809a8f9b2d9e85dd7eb/wal-000000038 (ops 183-187)
I20260812 06:17:45.360298 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: LogGCOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.022s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:17:45.360751 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling UndoDeltaBlockGCOp(18000291c01a4809a8f9b2d9e85dd7eb): 447 bytes on disk
I20260812 06:17:45.361375 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: UndoDeltaBlockGCOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":113,"lbm_reads_lt_1ms":4}
I20260812 06:17:45.361915 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:45.386337 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.024s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4960,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.386862 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=2.188937
I20260812 06:17:45.397750 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4197,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.398281 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=1.000000
I20260812 06:17:45.620018 27526 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.817s	user 1.804s	sys 0.109s
I20260812 06:17:45.622733 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: MajorDeltaCompactionOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.224s	user 0.143s	sys 0.066s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979752,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1274,"lbm_read_time_us":14664,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37679,"lbm_writes_lt_1ms":743,"mutex_wait_us":370,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6656,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:17:45.623297 27711 maintenance_manager.cc:419] P 6cb6796743d7413db974777f33c2dcd1: Scheduling FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb): perf score=18.063937
I20260812 06:17:45.663137 27526 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.042s	user 0.001s	sys 0.001s
I20260812 06:17:45.663777 27526 tablet_server.cc:179] TabletServer@127.26.225.129:0 shutting down...
I20260812 06:17:45.688323 27640 maintenance_manager.cc:643] P 6cb6796743d7413db974777f33c2dcd1: FlushDeltaMemStoresOp(18000291c01a4809a8f9b2d9e85dd7eb) complete. Timing: real 0.065s	user 0.027s	sys 0.034s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":28852,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:45.688891 27526 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:45.689332 27526 tablet_replica.cc:333] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1: stopping tablet replica
I20260812 06:17:45.689564 27526 raft_consensus.cc:2243] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:45.689801 27526 raft_consensus.cc:2272] T 18000291c01a4809a8f9b2d9e85dd7eb P 6cb6796743d7413db974777f33c2dcd1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:45.704432 27526 tablet_server.cc:196] TabletServer@127.26.225.129:0 shutdown complete.
I20260812 06:17:45.709378 27526 master.cc:562] Master@127.26.225.190:34503 shutting down...
I20260812 06:17:45.713136 27526 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:45.713399 27526 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:45.713502 27526 tablet_replica.cc:333] T 00000000000000000000000000000000 P 96b85b59ce3646ccbdbaeee84826b9f4: stopping tablet replica
I20260812 06:17:45.725860 27526 master.cc:584] Master@127.26.225.190:34503 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5278 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:45.812742 27526 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.225.190:39907
I20260812 06:17:45.813352 27526 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:45.815718 27749 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:45.815865 27752 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:45.815816 27526 server_base.cc:1061] running on GCE node
W20260812 06:17:45.815743 27748 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:45.816147 27526 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:45.816193 27526 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:45.816208 27526 hybrid_clock.cc:648] HybridClock initialized: now 1786515465816209 us; error 0 us; skew 500 ppm
I20260812 06:17:45.817085 27526 webserver.cc:533] Webserver started at http://127.26.225.190:44151/ using document root <none> and password file <none>
I20260812 06:17:45.817325 27526 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:45.817376 27526 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:45.817431 27526 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:45.817777 27526 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/master-0-root/instance:
uuid: "e2791ad774304ea687d2b9f583eb9691"
format_stamp: "Formatted at 2026-08-12 06:17:45 on dist-test-slave-9gcw"
I20260812 06:17:45.819274 27526 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:45.820165 27758 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:45.820436 27526 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:45.820519 27526 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/master-0-root
uuid: "e2791ad774304ea687d2b9f583eb9691"
format_stamp: "Formatted at 2026-08-12 06:17:45 on dist-test-slave-9gcw"
I20260812 06:17:45.820590 27526 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:45.849647 27526 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:45.850117 27526 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:45.854609 27526 rpc_server.cc:307] RPC server started. Bound to: 127.26.225.190:39907
I20260812 06:17:45.856158 27816 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.225.190:39907 every 8 connection(s)
I20260812 06:17:45.857532 27817 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:45.870397 27817 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691: Bootstrap starting.
I20260812 06:17:45.871315 27817 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:45.872399 27817 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691: No bootstrap required, opened a new log
I20260812 06:17:45.872876 27817 raft_consensus.cc:359] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e2791ad774304ea687d2b9f583eb9691" member_type: VOTER }
I20260812 06:17:45.872964 27817 raft_consensus.cc:385] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:45.873020 27817 raft_consensus.cc:740] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e2791ad774304ea687d2b9f583eb9691, State: Initialized, Role: FOLLOWER
I20260812 06:17:45.873234 27817 consensus_queue.cc:260] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [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: "e2791ad774304ea687d2b9f583eb9691" member_type: VOTER }
I20260812 06:17:45.873310 27817 raft_consensus.cc:399] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:45.873381 27817 raft_consensus.cc:493] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:45.873466 27817 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:45.874199 27817 raft_consensus.cc:515] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e2791ad774304ea687d2b9f583eb9691" member_type: VOTER }
I20260812 06:17:45.874349 27817 leader_election.cc:304] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [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: e2791ad774304ea687d2b9f583eb9691; no voters: 
I20260812 06:17:45.874563 27817 leader_election.cc:290] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:45.874715 27821 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:45.874943 27821 raft_consensus.cc:697] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [term 1 LEADER]: Becoming Leader. State: Replica: e2791ad774304ea687d2b9f583eb9691, State: Running, Role: LEADER
I20260812 06:17:45.875025 27817 sys_catalog.cc:565] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:45.875104 27821 consensus_queue.cc:237] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [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: "e2791ad774304ea687d2b9f583eb9691" member_type: VOTER }
I20260812 06:17:45.875571 27822 sys_catalog.cc:455] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e2791ad774304ea687d2b9f583eb9691" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e2791ad774304ea687d2b9f583eb9691" member_type: VOTER } }
I20260812 06:17:45.875612 27823 sys_catalog.cc:455] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [sys.catalog]: SysCatalogTable state changed. Reason: New leader e2791ad774304ea687d2b9f583eb9691. Latest consensus state: current_term: 1 leader_uuid: "e2791ad774304ea687d2b9f583eb9691" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e2791ad774304ea687d2b9f583eb9691" member_type: VOTER } }
I20260812 06:17:45.875674 27822 sys_catalog.cc:458] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:45.875686 27823 sys_catalog.cc:458] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:45.875988 27827 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:45.876734 27827 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:45.877081 27526 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:45.878757 27827 catalog_manager.cc:1383] Generated new cluster ID: 34f2135d49cc4a9d8203af69d75fe3eb
I20260812 06:17:45.878822 27827 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:45.891211 27827 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:45.892132 27827 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:45.898768 27827 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691: Generated new TSK 0
I20260812 06:17:45.898994 27827 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:45.909621 27526 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:45.912166 27846 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:45.912166 27843 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:45.912258 27842 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:45.912221 27526 server_base.cc:1061] running on GCE node
I20260812 06:17:45.912622 27526 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:45.912667 27526 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:45.912683 27526 hybrid_clock.cc:648] HybridClock initialized: now 1786515465912682 us; error 0 us; skew 500 ppm
I20260812 06:17:45.913677 27526 webserver.cc:533] Webserver started at http://127.26.225.129:42789/ using document root <none> and password file <none>
I20260812 06:17:45.913861 27526 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:45.913913 27526 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:45.913967 27526 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:45.914337 27526 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/instance:
uuid: "68fd3f7744184b9185280225f91ed3eb"
format_stamp: "Formatted at 2026-08-12 06:17:45 on dist-test-slave-9gcw"
I20260812 06:17:45.915896 27526 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:45.916965 27851 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:45.917304 27526 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:45.917398 27526 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root
uuid: "68fd3f7744184b9185280225f91ed3eb"
format_stamp: "Formatted at 2026-08-12 06:17:45 on dist-test-slave-9gcw"
I20260812 06:17:45.917495 27526 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:45.936362 27526 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:45.936801 27526 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:45.937212 27526 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:45.937963 27526 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:45.938022 27526 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:45.938088 27526 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:45.938128 27526 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:45.944461 27526 rpc_server.cc:307] RPC server started. Bound to: 127.26.225.129:45007
I20260812 06:17:45.944479 27930 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.225.129:45007 every 8 connection(s)
I20260812 06:17:45.951061 27931 heartbeater.cc:344] Connected to a master server at 127.26.225.190:39907
I20260812 06:17:45.951189 27931 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:45.951510 27931 heartbeater.cc:507] Master 127.26.225.190:39907 requested a full tablet report, sending...
I20260812 06:17:45.952291 27775 ts_manager.cc:194] Registered new tserver with Master: 68fd3f7744184b9185280225f91ed3eb (127.26.225.129:45007)
I20260812 06:17:45.952828 27526 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.007664487s
I20260812 06:17:45.953096 27775 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56338
I20260812 06:17:45.964761 27775 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56350:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:45.974506 27888 tablet_service.cc:1511] Processing CreateTablet for tablet 1ea39cc67cb74e959b8c11b0dc1621f9 (DEFAULT_TABLE table=heavy-update-compaction-test [id=b0f65f9159374df0ba67fc5254b8ebd7]), partition=
I20260812 06:17:45.974851 27888 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1ea39cc67cb74e959b8c11b0dc1621f9. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:45.977068 27944 tablet_bootstrap.cc:492] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Bootstrap starting.
I20260812 06:17:45.978472 27944 tablet_bootstrap.cc:654] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:45.979681 27944 tablet_bootstrap.cc:492] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: No bootstrap required, opened a new log
I20260812 06:17:45.979801 27944 ts_tablet_manager.cc:1403] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:17:45.980242 27944 raft_consensus.cc:359] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "68fd3f7744184b9185280225f91ed3eb" member_type: VOTER last_known_addr { host: "127.26.225.129" port: 45007 } }
I20260812 06:17:45.980333 27944 raft_consensus.cc:385] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:45.980356 27944 raft_consensus.cc:740] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 68fd3f7744184b9185280225f91ed3eb, State: Initialized, Role: FOLLOWER
I20260812 06:17:45.980487 27944 consensus_queue.cc:260] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb [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: "68fd3f7744184b9185280225f91ed3eb" member_type: VOTER last_known_addr { host: "127.26.225.129" port: 45007 } }
I20260812 06:17:45.980576 27944 raft_consensus.cc:399] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:45.980600 27944 raft_consensus.cc:493] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:45.980635 27944 raft_consensus.cc:3060] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:45.981463 27944 raft_consensus.cc:515] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "68fd3f7744184b9185280225f91ed3eb" member_type: VOTER last_known_addr { host: "127.26.225.129" port: 45007 } }
I20260812 06:17:45.981581 27944 leader_election.cc:304] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb [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: 68fd3f7744184b9185280225f91ed3eb; no voters: 
I20260812 06:17:45.981745 27944 leader_election.cc:290] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:45.981886 27946 raft_consensus.cc:2804] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:45.982128 27931 heartbeater.cc:499] Master 127.26.225.190:39907 was elected leader, sending a full tablet report...
I20260812 06:17:45.982107 27944 ts_tablet_manager.cc:1434] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:17:45.982118 27946 raft_consensus.cc:697] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb [term 1 LEADER]: Becoming Leader. State: Replica: 68fd3f7744184b9185280225f91ed3eb, State: Running, Role: LEADER
I20260812 06:17:45.982331 27946 consensus_queue.cc:237] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb [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: "68fd3f7744184b9185280225f91ed3eb" member_type: VOTER last_known_addr { host: "127.26.225.129" port: 45007 } }
I20260812 06:17:45.983719 27775 catalog_manager.cc:5719] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb reported cstate change: term changed from 0 to 1, leader changed from <none> to 68fd3f7744184b9185280225f91ed3eb (127.26.225.129). New cstate: current_term: 1 leader_uuid: "68fd3f7744184b9185280225f91ed3eb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "68fd3f7744184b9185280225f91ed3eb" member_type: VOTER last_known_addr { host: "127.26.225.129" port: 45007 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:46.041447 27526 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.018s	sys 0.004s
I20260812 06:17:46.195608 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushMRSOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=19.054940
I20260812 06:17:46.339156 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushMRSOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.143s	user 0.097s	sys 0.043s Metrics: {"bytes_written":12512604,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":830,"drs_written":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35621,"lbm_writes_lt_1ms":772,"mutex_wait_us":791,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1525}
I20260812 06:17:46.340039 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling LogGCOp(1ea39cc67cb74e959b8c11b0dc1621f9): free 20743880 bytes of WAL
I20260812 06:17:46.340276 27856 log_reader.cc:385] T 1ea39cc67cb74e959b8c11b0dc1621f9: removed 2 log segments from log reader
I20260812 06:17:46.340344 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000001 (ops 1-6)
I20260812 06:17:46.340422 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000002 (ops 7-11)
I20260812 06:17:46.345672 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: LogGCOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:17:46.346138 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:46.363471 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.017s	user 0.003s	sys 0.006s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":4005,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:17:46.363967 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:46.373797 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3637,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:46.374265 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:46.541322 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.167s	user 0.116s	sys 0.041s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405538,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1368,"lbm_read_time_us":11386,"lbm_reads_lt_1ms":563,"lbm_write_time_us":27683,"lbm_writes_lt_1ms":533,"mutex_wait_us":368,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":431,"threads_started":5,"update_count":2450}
I20260812 06:17:46.541975 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling UndoDeltaBlockGCOp(1ea39cc67cb74e959b8c11b0dc1621f9): 16821647 bytes on disk
I20260812 06:17:46.542500 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: UndoDeltaBlockGCOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:17:46.543020 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=14.095187
I20260812 06:17:46.594137 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.051s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20756,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:46.594733 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:46.606456 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.012s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3881,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.607072 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:46.766646 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.159s	user 0.123s	sys 0.029s 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":458,"lbm_read_time_us":10301,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29708,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2500}
I20260812 06:17:46.767262 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=14.095187
I20260812 06:17:46.820036 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.053s	user 0.028s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22348,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:46.820555 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:46.983848 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.163s	user 0.115s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":146,"lbm_read_time_us":9527,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27642,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2000}
I20260812 06:17:46.984606 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=14.095187
I20260812 06:17:47.039691 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.055s	user 0.025s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26069,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:47.040235 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:47.051895 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.011s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4526,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.052480 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:47.235977 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.183s	user 0.133s	sys 0.048s 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":190,"lbm_read_time_us":9679,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29697,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2500}
I20260812 06:17:47.236706 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=14.095187
I20260812 06:17:47.288205 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.051s	user 0.039s	sys 0.009s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22761,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:47.288836 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:47.304584 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6010,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.305358 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:47.489703 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.184s	user 0.142s	sys 0.031s 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":931,"lbm_read_time_us":9502,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35570,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":75136,"update_count":2500}
I20260812 06:17:47.490433 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=14.095187
I20260812 06:17:47.537259 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.047s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20358,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:47.537808 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:47.549245 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4125,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.549829 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushMRSOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:47.579349 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushMRSOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.029s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":1601,"drs_written":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1808,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:47.580025 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling LogGCOp(1ea39cc67cb74e959b8c11b0dc1621f9): free 112692371 bytes of WAL
I20260812 06:17:47.580310 27856 log_reader.cc:385] T 1ea39cc67cb74e959b8c11b0dc1621f9: removed 11 log segments from log reader
I20260812 06:17:47.580381 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000003 (ops 12-16)
I20260812 06:17:47.580428 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000004 (ops 17-21)
I20260812 06:17:47.580469 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000005 (ops 22-26)
I20260812 06:17:47.580500 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000006 (ops 27-31)
I20260812 06:17:47.580539 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000007 (ops 32-36)
I20260812 06:17:47.580580 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000008 (ops 37-41)
I20260812 06:17:47.580610 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000009 (ops 42-46)
I20260812 06:17:47.580648 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000010 (ops 47-51)
I20260812 06:17:47.580677 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000011 (ops 52-56)
I20260812 06:17:47.580714 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000012 (ops 57-61)
I20260812 06:17:47.580753 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000013 (ops 62-66)
I20260812 06:17:47.608275 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: LogGCOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:47.608958 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling UndoDeltaBlockGCOp(1ea39cc67cb74e959b8c11b0dc1621f9): 447 bytes on disk
I20260812 06:17:47.609488 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: UndoDeltaBlockGCOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:17:47.609998 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:47.646006 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.036s	user 0.012s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5365,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.646590 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling LogGCOp(1ea39cc67cb74e959b8c11b0dc1621f9): free 11564875 bytes of WAL
I20260812 06:17:47.646836 27856 log_reader.cc:385] T 1ea39cc67cb74e959b8c11b0dc1621f9: removed 1 log segments from log reader
I20260812 06:17:47.646905 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000014 (ops 67-70)
I20260812 06:17:47.649358 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: LogGCOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:47.649758 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:47.661789 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4615,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.662345 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:47.947990 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.285s	user 0.185s	sys 0.100s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020745,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":463,"lbm_read_time_us":19713,"lbm_reads_lt_1ms":774,"lbm_write_time_us":46795,"lbm_writes_lt_1ms":743,"mutex_wait_us":78,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":77184,"thread_start_us":101,"threads_started":1,"update_count":3500}
I20260812 06:17:47.948920 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=18.063937
I20260812 06:17:48.025662 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.076s	user 0.042s	sys 0.031s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":36972,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:17:48.026221 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:48.037873 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4010,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.038373 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:48.260586 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.222s	user 0.137s	sys 0.072s 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":931,"lbm_read_time_us":13009,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35821,"lbm_writes_lt_1ms":643,"mutex_wait_us":323,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":3000}
I20260812 06:17:48.261407 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=18.063937
I20260812 06:17:48.331988 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.070s	user 0.035s	sys 0.029s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":30246,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:17:48.332520 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:48.343159 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4016,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.343973 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:48.562953 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.219s	user 0.139s	sys 0.079s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":209,"lbm_read_time_us":14540,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37874,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:17:48.563537 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=18.063937
I20260812 06:17:48.619081 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.055s	user 0.030s	sys 0.020s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":23533,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:48.619603 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:48.803336 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.184s	user 0.135s	sys 0.048s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24815565,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1058,"lbm_read_time_us":13415,"lbm_reads_lt_1ms":563,"lbm_write_time_us":32547,"lbm_writes_lt_1ms":543,"mutex_wait_us":286,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:17:48.804064 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=14.095187
I20260812 06:17:48.858480 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.054s	user 0.029s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19676,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:48.858991 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:48.870571 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4150,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.871127 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:49.057427 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.186s	user 0.114s	sys 0.064s 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":865,"lbm_read_time_us":12303,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31574,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":72832,"update_count":2500}
I20260812 06:17:49.058161 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=14.095187
I20260812 06:17:49.111900 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.054s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19757,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:49.112433 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:49.123375 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4291,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.123854 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushMRSOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:49.167801 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushMRSOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.044s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1572,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1361,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:49.168526 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling LogGCOp(1ea39cc67cb74e959b8c11b0dc1621f9): free 112239316 bytes of WAL
I20260812 06:17:49.168753 27856 log_reader.cc:385] T 1ea39cc67cb74e959b8c11b0dc1621f9: removed 11 log segments from log reader
I20260812 06:17:49.168826 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000015 (ops 71-75)
I20260812 06:17:49.168882 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000016 (ops 76-80)
I20260812 06:17:49.168921 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000017 (ops 81-85)
I20260812 06:17:49.168962 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000018 (ops 86-90)
I20260812 06:17:49.168996 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000019 (ops 91-94)
I20260812 06:17:49.169034 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000020 (ops 95-99)
I20260812 06:17:49.169071 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000021 (ops 100-104)
I20260812 06:17:49.169108 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000022 (ops 105-109)
I20260812 06:17:49.169168 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000023 (ops 110-114)
I20260812 06:17:49.169209 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000024 (ops 115-119)
I20260812 06:17:49.169246 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000025 (ops 120-124)
I20260812 06:17:49.193173 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: LogGCOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.024s	user 0.002s	sys 0.019s Metrics: {}
I20260812 06:17:49.193646 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling UndoDeltaBlockGCOp(1ea39cc67cb74e959b8c11b0dc1621f9): 461 bytes on disk
I20260812 06:17:49.194231 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: UndoDeltaBlockGCOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:17:49.194903 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:49.210384 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.015s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4363,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.210916 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:49.221570 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3987,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.222215 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:49.475428 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.253s	user 0.182s	sys 0.060s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020745,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":518,"lbm_read_time_us":16888,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39194,"lbm_writes_lt_1ms":743,"mutex_wait_us":23,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":21632,"thread_start_us":105,"threads_started":1,"update_count":3500}
I20260812 06:17:49.476281 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=18.063937
I20260812 06:17:49.547747 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.071s	user 0.032s	sys 0.027s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":27808,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:49.548275 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:49.558907 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4058,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.559564 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:49.774350 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.215s	user 0.150s	sys 0.059s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":914,"lbm_read_time_us":14495,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36390,"lbm_writes_lt_1ms":643,"mutex_wait_us":322,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":3000}
I20260812 06:17:49.775134 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=16.079562
I20260812 06:17:49.834637 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.059s	user 0.047s	sys 0.008s Metrics: {"bytes_written":17886768,"delete_count":0,"lbm_write_time_us":25539,"lbm_writes_lt_1ms":439,"reinsert_count":0,"update_count":2180}
I20260812 06:17:49.835150 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.196750
I20260812 06:17:49.855481 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.020s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3036009,"delete_count":0,"lbm_write_time_us":4125,"lbm_writes_lt_1ms":77,"reinsert_count":0,"update_count":370}
I20260812 06:17:49.856050 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:49.867009 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4163,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:49.867585 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:50.109272 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.241s	user 0.143s	sys 0.094s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918177,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":337,"lbm_read_time_us":17652,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37443,"lbm_writes_lt_1ms":643,"mutex_wait_us":66,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":3000}
I20260812 06:17:50.110845 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=17.071750
I20260812 06:17:50.175486 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.062s	user 0.029s	sys 0.016s Metrics: {"bytes_written":19609789,"delete_count":0,"lbm_write_time_us":21656,"lbm_writes_lt_1ms":481,"reinsert_count":0,"update_count":2390}
I20260812 06:17:50.176036 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=3.181125
I20260812 06:17:50.191299 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":5005194,"delete_count":0,"lbm_write_time_us":5986,"lbm_writes_lt_1ms":125,"reinsert_count":0,"update_count":610}
I20260812 06:17:50.192011 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:50.409303 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.217s	user 0.136s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918106,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":814,"lbm_read_time_us":13894,"lbm_reads_lt_1ms":664,"lbm_write_time_us":35539,"lbm_writes_lt_1ms":643,"mutex_wait_us":351,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":86528,"update_count":3000}
I20260812 06:17:50.409935 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=18.063937
I20260812 06:17:50.479086 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.069s	user 0.033s	sys 0.021s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25290,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:50.479705 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:50.492295 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4296,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.492926 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:50.706786 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.214s	user 0.154s	sys 0.059s 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":332,"lbm_read_time_us":15261,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36254,"lbm_writes_lt_1ms":643,"mutex_wait_us":64,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":3000}
I20260812 06:17:50.707587 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=14.095187
I20260812 06:17:50.759806 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.052s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22020,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.760377 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:50.786338 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.026s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6014,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.786849 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:50.801800 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.015s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5799,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.802380 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushMRSOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:50.837604 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushMRSOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.035s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1649,"drs_written":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1503,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:50.838317 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling LogGCOp(1ea39cc67cb74e959b8c11b0dc1621f9): free 129320721 bytes of WAL
I20260812 06:17:50.838547 27856 log_reader.cc:385] T 1ea39cc67cb74e959b8c11b0dc1621f9: removed 13 log segments from log reader
I20260812 06:17:50.838595 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000026 (ops 125-129)
I20260812 06:17:50.838624 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000027 (ops 130-134)
I20260812 06:17:50.838686 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000028 (ops 135-139)
I20260812 06:17:50.838719 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000029 (ops 140-144)
I20260812 06:17:50.838755 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000030 (ops 145-149)
I20260812 06:17:50.838815 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000031 (ops 150-154)
I20260812 06:17:50.838853 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000032 (ops 155-158)
I20260812 06:17:50.838896 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000033 (ops 159-163)
I20260812 06:17:50.838923 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000034 (ops 164-168)
I20260812 06:17:50.838961 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000035 (ops 169-172)
I20260812 06:17:50.838999 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000036 (ops 173-177)
I20260812 06:17:50.839037 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000037 (ops 178-182)
I20260812 06:17:50.839075 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000038 (ops 183-187)
I20260812 06:17:50.867766 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: LogGCOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:50.868366 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling UndoDeltaBlockGCOp(1ea39cc67cb74e959b8c11b0dc1621f9): 492 bytes on disk
I20260812 06:17:50.868932 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: UndoDeltaBlockGCOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:17:50.869632 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=3.181125
I20260812 06:17:50.882972 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4647,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:50.883504 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling LogGCOp(1ea39cc67cb74e959b8c11b0dc1621f9): free 12018004 bytes of WAL
I20260812 06:17:50.883739 27856 log_reader.cc:385] T 1ea39cc67cb74e959b8c11b0dc1621f9: removed 1 log segments from log reader
I20260812 06:17:50.883808 27856 log.cc:1079] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: Deleting log segment in path: /tmp/dist-test-taskYV5gfG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515460524742-27526-0/minicluster-data/ts-0-root/wals/1ea39cc67cb74e959b8c11b0dc1621f9/wal-000000039 (ops 188-192)
I20260812 06:17:50.886353 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: LogGCOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:50.886726 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=2.188937
I20260812 06:17:50.897866 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3877,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:50.898486 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=1.000000
I20260812 06:17:51.104790 27526 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.063s	user 1.879s	sys 0.209s
I20260812 06:17:51.149646 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: MajorDeltaCompactionOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.251s	user 0.174s	sys 0.076s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123261,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"lbm_read_time_us":19976,"lbm_reads_lt_1ms":871,"lbm_write_time_us":48808,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":4000}
I20260812 06:17:51.150144 27932 maintenance_manager.cc:419] P 68fd3f7744184b9185280225f91ed3eb: Scheduling FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9): perf score=14.095187
I20260812 06:17:51.187922 27526 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.083s	user 0.000s	sys 0.000s
I20260812 06:17:51.188417 27526 tablet_server.cc:179] TabletServer@127.26.225.129:0 shutting down...
I20260812 06:17:51.240743 27856 maintenance_manager.cc:643] P 68fd3f7744184b9185280225f91ed3eb: FlushDeltaMemStoresOp(1ea39cc67cb74e959b8c11b0dc1621f9) complete. Timing: real 0.090s	user 0.025s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18213,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:51.241518 27526 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:51.241748 27526 tablet_replica.cc:333] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb: stopping tablet replica
I20260812 06:17:51.241911 27526 raft_consensus.cc:2243] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:51.242113 27526 raft_consensus.cc:2272] T 1ea39cc67cb74e959b8c11b0dc1621f9 P 68fd3f7744184b9185280225f91ed3eb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:51.245440 27526 tablet_server.cc:196] TabletServer@127.26.225.129:0 shutdown complete.
I20260812 06:17:51.248068 27526 master.cc:562] Master@127.26.225.190:39907 shutting down...
I20260812 06:17:51.252107 27526 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:51.252252 27526 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:51.252302 27526 tablet_replica.cc:333] T 00000000000000000000000000000000 P e2791ad774304ea687d2b9f583eb9691: stopping tablet replica
I20260812 06:17:51.264911 27526 master.cc:584] Master@127.26.225.190:39907 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5537 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10816 ms total)

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