[==========] 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:47.923659  5298 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.44.190:40659
I20260812 06:17:47.924571  5298 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:47.925348  5298 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:47.932375  5298 server_base.cc:1061] running on GCE node
W20260812 06:17:47.932331  5303 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:47.932543  5306 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:47.932468  5304 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:47.933077  5298 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:47.933197  5298 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:47.933244  5298 hybrid_clock.cc:648] HybridClock initialized: now 1786515467933241 us; error 0 us; skew 500 ppm
I20260812 06:17:47.935153  5298 webserver.cc:533] Webserver started at http://127.5.44.190:39045/ using document root <none> and password file <none>
I20260812 06:17:47.935643  5298 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:47.935698  5298 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:47.935945  5298 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:47.937449  5298 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/master-0-root/instance:
uuid: "6abc433fb54d4c89b0b0c9a134e80673"
format_stamp: "Formatted at 2026-08-12 06:17:47 on dist-test-slave-7c35"
I20260812 06:17:47.940708  5298 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:17:47.942553  5312 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:47.943542  5298 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:47.943666  5298 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/master-0-root
uuid: "6abc433fb54d4c89b0b0c9a134e80673"
format_stamp: "Formatted at 2026-08-12 06:17:47 on dist-test-slave-7c35"
I20260812 06:17:47.943766  5298 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-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:47.960038  5298 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:47.960621  5298 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:47.960794  5298 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:47.968693  5298 rpc_server.cc:307] RPC server started. Bound to: 127.5.44.190:40659
I20260812 06:17:47.968703  5378 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.44.190:40659 every 8 connection(s)
I20260812 06:17:47.970839  5379 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:47.975888  5379 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673: Bootstrap starting.
I20260812 06:17:47.978049  5379 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:47.978888  5379 log.cc:826] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:47.980388  5379 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673: No bootstrap required, opened a new log
I20260812 06:17:47.982973  5379 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6abc433fb54d4c89b0b0c9a134e80673" member_type: VOTER }
I20260812 06:17:47.983116  5379 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:47.983153  5379 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6abc433fb54d4c89b0b0c9a134e80673, State: Initialized, Role: FOLLOWER
I20260812 06:17:47.983615  5379 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [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: "6abc433fb54d4c89b0b0c9a134e80673" member_type: VOTER }
I20260812 06:17:47.983757  5379 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:47.983800  5379 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:47.983880  5379 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:47.984586  5379 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6abc433fb54d4c89b0b0c9a134e80673" member_type: VOTER }
I20260812 06:17:47.984933  5379 leader_election.cc:304] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [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: 6abc433fb54d4c89b0b0c9a134e80673; no voters: 
I20260812 06:17:47.985168  5379 leader_election.cc:290] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:47.985353  5382 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:47.985638  5382 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [term 1 LEADER]: Becoming Leader. State: Replica: 6abc433fb54d4c89b0b0c9a134e80673, State: Running, Role: LEADER
I20260812 06:17:47.986016  5382 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [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: "6abc433fb54d4c89b0b0c9a134e80673" member_type: VOTER }
I20260812 06:17:47.986150  5379 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:47.987993  5383 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6abc433fb54d4c89b0b0c9a134e80673" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6abc433fb54d4c89b0b0c9a134e80673" member_type: VOTER } }
I20260812 06:17:47.988008  5384 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6abc433fb54d4c89b0b0c9a134e80673. Latest consensus state: current_term: 1 leader_uuid: "6abc433fb54d4c89b0b0c9a134e80673" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6abc433fb54d4c89b0b0c9a134e80673" member_type: VOTER } }
I20260812 06:17:47.988131  5383 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:47.988130  5384 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:47.988489  5399 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:47.988581  5298 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:47.990628  5399 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:47.995373  5399 catalog_manager.cc:1383] Generated new cluster ID: da6bd6d57d5d4a7ab52154f9a0207093
I20260812 06:17:47.995447  5399 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:48.003505  5399 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:48.004356  5399 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:48.015966  5399 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673: Generated new TSK 0
I20260812 06:17:48.016507  5399 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:48.021008  5298 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:48.023460  5407 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:48.023610  5410 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:48.023725  5408 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:48.023795  5298 server_base.cc:1061] running on GCE node
I20260812 06:17:48.024024  5298 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:48.024106  5298 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:48.024137  5298 hybrid_clock.cc:648] HybridClock initialized: now 1786515468024136 us; error 0 us; skew 500 ppm
I20260812 06:17:48.025034  5298 webserver.cc:533] Webserver started at http://127.5.44.129:36793/ using document root <none> and password file <none>
I20260812 06:17:48.025207  5298 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:48.025274  5298 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:48.025347  5298 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:48.025746  5298 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/instance:
uuid: "c7e2815b6eee4d4f842ffb2c29ae19a6"
format_stamp: "Formatted at 2026-08-12 06:17:48 on dist-test-slave-7c35"
I20260812 06:17:48.027244  5298 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:48.028301  5416 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:48.028546  5298 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:48.028618  5298 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root
uuid: "c7e2815b6eee4d4f842ffb2c29ae19a6"
format_stamp: "Formatted at 2026-08-12 06:17:48 on dist-test-slave-7c35"
I20260812 06:17:48.028700  5298 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-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:48.037906  5298 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:48.038300  5298 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:48.038762  5298 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:48.039914  5298 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:48.039968  5298 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:48.040031  5298 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:48.040071  5298 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:48.046893  5298 rpc_server.cc:307] RPC server started. Bound to: 127.5.44.129:36261
I20260812 06:17:48.047039  5489 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.44.129:36261 every 8 connection(s)
I20260812 06:17:48.056874  5490 heartbeater.cc:344] Connected to a master server at 127.5.44.190:40659
I20260812 06:17:48.057107  5490 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:48.057498  5490 heartbeater.cc:507] Master 127.5.44.190:40659 requested a full tablet report, sending...
I20260812 06:17:48.058964  5334 ts_manager.cc:194] Registered new tserver with Master: c7e2815b6eee4d4f842ffb2c29ae19a6 (127.5.44.129:36261)
I20260812 06:17:48.059020  5298 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011354895s
I20260812 06:17:48.060387  5334 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34744
I20260812 06:17:48.067950  5334 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34754:
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:48.081349  5447 tablet_service.cc:1511] Processing CreateTablet for tablet 420432930c7349409e07393d399cd003 (DEFAULT_TABLE table=heavy-update-compaction-test [id=db88d39ad8b14ff599579cdbe9539127]), partition=
I20260812 06:17:48.081785  5447 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 420432930c7349409e07393d399cd003. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:48.084484  5504 tablet_bootstrap.cc:492] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Bootstrap starting.
I20260812 06:17:48.085467  5504 tablet_bootstrap.cc:654] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:48.086483  5504 tablet_bootstrap.cc:492] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: No bootstrap required, opened a new log
I20260812 06:17:48.086611  5504 ts_tablet_manager.cc:1403] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:48.087072  5504 raft_consensus.cc:359] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c7e2815b6eee4d4f842ffb2c29ae19a6" member_type: VOTER last_known_addr { host: "127.5.44.129" port: 36261 } }
I20260812 06:17:48.087185  5504 raft_consensus.cc:385] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:48.087235  5504 raft_consensus.cc:740] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c7e2815b6eee4d4f842ffb2c29ae19a6, State: Initialized, Role: FOLLOWER
I20260812 06:17:48.087404  5504 consensus_queue.cc:260] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6 [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: "c7e2815b6eee4d4f842ffb2c29ae19a6" member_type: VOTER last_known_addr { host: "127.5.44.129" port: 36261 } }
I20260812 06:17:48.087508  5504 raft_consensus.cc:399] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:48.087564  5504 raft_consensus.cc:493] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:48.087617  5504 raft_consensus.cc:3060] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:48.088454  5504 raft_consensus.cc:515] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c7e2815b6eee4d4f842ffb2c29ae19a6" member_type: VOTER last_known_addr { host: "127.5.44.129" port: 36261 } }
I20260812 06:17:48.088616  5504 leader_election.cc:304] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6 [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: c7e2815b6eee4d4f842ffb2c29ae19a6; no voters: 
I20260812 06:17:48.088837  5504 leader_election.cc:290] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:48.088936  5506 raft_consensus.cc:2804] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:48.089154  5504 ts_tablet_manager.cc:1434] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:48.089385  5490 heartbeater.cc:499] Master 127.5.44.190:40659 was elected leader, sending a full tablet report...
I20260812 06:17:48.089180  5506 raft_consensus.cc:697] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6 [term 1 LEADER]: Becoming Leader. State: Replica: c7e2815b6eee4d4f842ffb2c29ae19a6, State: Running, Role: LEADER
I20260812 06:17:48.089798  5506 consensus_queue.cc:237] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6 [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: "c7e2815b6eee4d4f842ffb2c29ae19a6" member_type: VOTER last_known_addr { host: "127.5.44.129" port: 36261 } }
I20260812 06:17:48.092275  5334 catalog_manager.cc:5719] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6 reported cstate change: term changed from 0 to 1, leader changed from <none> to c7e2815b6eee4d4f842ffb2c29ae19a6 (127.5.44.129). New cstate: current_term: 1 leader_uuid: "c7e2815b6eee4d4f842ffb2c29ae19a6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c7e2815b6eee4d4f842ffb2c29ae19a6" member_type: VOTER last_known_addr { host: "127.5.44.129" port: 36261 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:48.154827  5298 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.008s	sys 0.017s
I20260812 06:17:48.298084  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushMRSOp(420432930c7349409e07393d399cd003): perf score=19.054940
I20260812 06:17:48.515278  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushMRSOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.217s	user 0.165s	sys 0.047s Metrics: {"bytes_written":17148341,"cfile_init":1,"compiler_manager_pool.queue_time_us":181,"delete_count":0,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1081,"drs_written":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4,"lbm_write_time_us":55753,"lbm_writes_lt_1ms":875,"mutex_wait_us":144,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":222976,"thread_start_us":116,"threads_started":1,"update_count":2090}
I20260812 06:17:48.516407  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling LogGCOp(420432930c7349409e07393d399cd003): free 20743880 bytes of WAL
I20260812 06:17:48.516772  5421 log_reader.cc:385] T 420432930c7349409e07393d399cd003: removed 2 log segments from log reader
I20260812 06:17:48.516845  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000001 (ops 1-6)
I20260812 06:17:48.516896  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000002 (ops 7-11)
I20260812 06:17:48.522001  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: LogGCOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:48.522296  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling UndoDeltaBlockGCOp(420432930c7349409e07393d399cd003): 16411393 bytes on disk
I20260812 06:17:48.522958  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: UndoDeltaBlockGCOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:17:48.523353  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=6.157687
I20260812 06:17:48.550683  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.027s	user 0.013s	sys 0.011s Metrics: {"bytes_written":7466648,"delete_count":0,"lbm_write_time_us":11328,"lbm_writes_lt_1ms":185,"mutex_wait_us":1,"reinsert_count":0,"update_count":910}
I20260812 06:17:48.551151  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:48.745777  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.194s	user 0.126s	sys 0.069s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877111,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":494,"lbm_read_time_us":10721,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34839,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":241,"threads_started":5,"update_count":3000}
I20260812 06:17:48.746323  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=14.095187
I20260812 06:17:48.797567  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.051s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22276,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:48.798084  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:48.943009  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.145s	user 0.102s	sys 0.042s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":427,"lbm_read_time_us":7998,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24725,"lbm_writes_lt_1ms":443,"mutex_wait_us":68,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:48.943614  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=10.126437
I20260812 06:17:48.993185  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.049s	user 0.010s	sys 0.021s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13391,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:48.993633  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=3.181125
I20260812 06:17:49.007682  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.014s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4260,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:49.008073  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:49.017004  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.009s	user 0.001s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3445,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:49.017505  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:49.212658  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.195s	user 0.144s	sys 0.043s 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":272,"lbm_read_time_us":15140,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31099,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":639616,"update_count":2500}
I20260812 06:17:49.213449  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=11.118625
I20260812 06:17:49.249778  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.036s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15711,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:49.250332  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:49.264621  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5065,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:49.265161  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:49.388669  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.123s	user 0.107s	sys 0.015s 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":384,"lbm_read_time_us":8804,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24717,"lbm_writes_lt_1ms":443,"mutex_wait_us":69,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:17:49.389324  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=10.126437
I20260812 06:17:49.421684  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.032s	user 0.013s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":12327,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:49.422228  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:49.435020  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.012s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4544,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.435509  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:49.562990  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.127s	user 0.076s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":982,"lbm_read_time_us":8036,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24721,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2000}
I20260812 06:17:49.563638  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=10.126437
I20260812 06:17:49.612282  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.048s	user 0.021s	sys 0.025s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":22550,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:49.612895  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:49.628837  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5870,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.629419  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:49.748804  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.119s	user 0.083s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":368,"lbm_read_time_us":9671,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21456,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:49.749420  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=10.126437
I20260812 06:17:49.793521  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.044s	user 0.034s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15353,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:49.794097  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:49.804307  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3934,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.804816  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushMRSOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:49.842777  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushMRSOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.038s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1401,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1946,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:49.843612  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling LogGCOp(420432930c7349409e07393d399cd003): free 124257257 bytes of WAL
I20260812 06:17:49.843835  5421 log_reader.cc:385] T 420432930c7349409e07393d399cd003: removed 12 log segments from log reader
I20260812 06:17:49.843879  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000003 (ops 12-16)
I20260812 06:17:49.843906  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000004 (ops 17-21)
I20260812 06:17:49.843973  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000005 (ops 22-26)
I20260812 06:17:49.844013  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000006 (ops 27-31)
I20260812 06:17:49.844051  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000007 (ops 32-36)
I20260812 06:17:49.844089  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000008 (ops 37-41)
I20260812 06:17:49.844126  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000009 (ops 42-46)
I20260812 06:17:49.844164  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000010 (ops 47-50)
I20260812 06:17:49.844203  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000011 (ops 51-55)
I20260812 06:17:49.844241  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000012 (ops 56-60)
I20260812 06:17:49.844278  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000013 (ops 61-65)
I20260812 06:17:49.844316  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000014 (ops 66-70)
I20260812 06:17:49.869851  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: LogGCOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.026s	user 0.001s	sys 0.022s Metrics: {}
I20260812 06:17:49.870281  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=3.181125
I20260812 06:17:49.881686  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4096,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:49.882124  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling UndoDeltaBlockGCOp(420432930c7349409e07393d399cd003): 483 bytes on disk
I20260812 06:17:49.882507  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: UndoDeltaBlockGCOp(420432930c7349409e07393d399cd003) 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:49.883068  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:49.892272  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3516,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:49.892707  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:50.087580  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.195s	user 0.128s	sys 0.067s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":214,"lbm_read_time_us":12817,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30921,"lbm_writes_lt_1ms":643,"mutex_wait_us":28,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:17:50.088129  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=14.095187
I20260812 06:17:50.148120  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.060s	user 0.034s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24243,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.148566  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:50.290940  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.142s	user 0.092s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":211,"lbm_read_time_us":8339,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24829,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":79488,"update_count":2000}
I20260812 06:17:50.291617  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=14.095187
I20260812 06:17:50.343245  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.051s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20899,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.343735  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:50.354553  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3972,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.355136  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:50.535107  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.180s	user 0.114s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":522,"lbm_read_time_us":9338,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30224,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:50.535663  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=14.095187
I20260812 06:17:50.584157  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.048s	user 0.031s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":17644,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.584725  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:50.600008  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5632,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.600513  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:50.748337  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.148s	user 0.114s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":141,"lbm_read_time_us":9986,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26228,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:17:50.749013  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=14.095187
I20260812 06:17:50.795967  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.047s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19164,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.796464  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:50.811582  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5642,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.812283  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:50.962143  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.150s	user 0.112s	sys 0.028s 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":498,"lbm_read_time_us":9329,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30275,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:17:50.962967  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=14.095187
I20260812 06:17:51.005223  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.042s	user 0.024s	sys 0.013s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":17153,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:51.005719  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:51.016587  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3921,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.017012  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:51.158922  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.142s	user 0.108s	sys 0.034s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":536,"lbm_read_time_us":8651,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29428,"lbm_writes_lt_1ms":543,"mutex_wait_us":279,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:17:51.159512  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=10.126437
I20260812 06:17:51.190469  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.031s	user 0.021s	sys 0.006s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12545,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:51.190994  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:51.205628  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5418,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.206230  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushMRSOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:51.241923  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushMRSOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.035s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":190,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1479,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2015,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:51.242694  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling LogGCOp(420432930c7349409e07393d399cd003): free 121459497 bytes of WAL
I20260812 06:17:51.242954  5421 log_reader.cc:385] T 420432930c7349409e07393d399cd003: removed 12 log segments from log reader
I20260812 06:17:51.242998  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000015 (ops 71-75)
I20260812 06:17:51.243026  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000016 (ops 76-80)
I20260812 06:17:51.243083  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000017 (ops 81-85)
I20260812 06:17:51.243124  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000018 (ops 86-90)
I20260812 06:17:51.243163  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000019 (ops 91-95)
I20260812 06:17:51.243244  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000020 (ops 96-100)
I20260812 06:17:51.243291  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000021 (ops 101-105)
I20260812 06:17:51.243326  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000022 (ops 106-110)
I20260812 06:17:51.243364  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000023 (ops 111-115)
I20260812 06:17:51.243402  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000024 (ops 116-120)
I20260812 06:17:51.243446  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000025 (ops 121-125)
I20260812 06:17:51.243484  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000026 (ops 126-130)
I20260812 06:17:51.269134  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: LogGCOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.026s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:17:51.269567  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=3.181125
I20260812 06:17:51.289487  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.020s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6910,"lbm_writes_lt_1ms":113,"mutex_wait_us":2,"reinsert_count":0,"update_count":550}
I20260812 06:17:51.289954  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling UndoDeltaBlockGCOp(420432930c7349409e07393d399cd003): 472 bytes on disk
I20260812 06:17:51.290432  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: UndoDeltaBlockGCOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:17:51.290974  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:51.303982  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.013s	user 0.006s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4895,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:51.304459  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:51.469942  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.165s	user 0.129s	sys 0.034s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":658,"lbm_read_time_us":11117,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33688,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2432,"thread_start_us":86,"threads_started":1,"update_count":3000}
I20260812 06:17:51.470927  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=14.095187
I20260812 06:17:51.526211  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.055s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21697,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:51.526698  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:51.541606  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5397,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.542284  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:51.703341  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.161s	user 0.115s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":125,"lbm_read_time_us":11396,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31820,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:51.704028  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=11.118625
I20260812 06:17:51.734516  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.030s	user 0.015s	sys 0.012s Metrics: {"bytes_written":12471587,"delete_count":0,"lbm_write_time_us":13048,"lbm_writes_lt_1ms":307,"reinsert_count":0,"update_count":1520}
I20260812 06:17:51.735061  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:51.748476  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3938558,"delete_count":0,"lbm_write_time_us":4705,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:17:51.749258  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:51.908668  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.159s	user 0.108s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1260,"lbm_read_time_us":9433,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27105,"lbm_writes_lt_1ms":443,"mutex_wait_us":313,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:51.909230  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=14.095187
I20260812 06:17:51.976488  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.067s	user 0.029s	sys 0.032s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23428,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:51.977012  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:51.989223  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4630,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.989729  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:52.170948  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.181s	user 0.121s	sys 0.055s 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":221,"lbm_read_time_us":13913,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27922,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":102144,"update_count":2500}
I20260812 06:17:52.171686  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=14.095187
I20260812 06:17:52.224967  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.053s	user 0.021s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18940,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.225481  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:52.236689  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4085,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.237182  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:52.403805  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.166s	user 0.128s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":176,"lbm_read_time_us":9963,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26762,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2500}
I20260812 06:17:52.404527  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=14.095187
I20260812 06:17:52.453584  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.049s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21797,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.454121  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:52.469246  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.015s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6032,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.469684  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:52.628260  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.158s	user 0.116s	sys 0.030s 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":207,"lbm_read_time_us":8354,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31034,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:17:52.629034  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=14.095187
I20260812 06:17:52.675971  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.047s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18344,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.676509  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:52.687043  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3956,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.687798  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushMRSOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:52.719406  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushMRSOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.031s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":1336,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1938,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:52.720117  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling LogGCOp(420432930c7349409e07393d399cd003): free 132118537 bytes of WAL
I20260812 06:17:52.720373  5421 log_reader.cc:385] T 420432930c7349409e07393d399cd003: removed 13 log segments from log reader
I20260812 06:17:52.720431  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000027 (ops 131-135)
I20260812 06:17:52.720470  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000028 (ops 136-140)
I20260812 06:17:52.720503  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000029 (ops 141-145)
I20260812 06:17:52.720525  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000030 (ops 146-150)
I20260812 06:17:52.720546  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000031 (ops 151-155)
I20260812 06:17:52.720572  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000032 (ops 156-160)
I20260812 06:17:52.720606  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000033 (ops 161-164)
I20260812 06:17:52.720640  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000034 (ops 165-169)
I20260812 06:17:52.720662  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000035 (ops 170-174)
I20260812 06:17:52.720691  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000036 (ops 175-178)
I20260812 06:17:52.720719  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000037 (ops 179-183)
I20260812 06:17:52.720749  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000038 (ops 184-188)
I20260812 06:17:52.720782  5421 log.cc:1079] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/420432930c7349409e07393d399cd003/wal-000000039 (ops 189-192)
I20260812 06:17:52.752264  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: LogGCOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.032s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:52.752830  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling UndoDeltaBlockGCOp(420432930c7349409e07393d399cd003): 483 bytes on disk
I20260812 06:17:52.753510  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: UndoDeltaBlockGCOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:17:52.754357  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:52.783051  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.029s	user 0.018s	sys 0.007s Metrics: {"bytes_written":4184707,"delete_count":0,"lbm_write_time_us":6487,"lbm_writes_lt_1ms":105,"reinsert_count":0,"update_count":510}
I20260812 06:17:52.783516  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003): perf score=2.188937
I20260812 06:17:52.794070  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: FlushDeltaMemStoresOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4020608,"delete_count":0,"lbm_write_time_us":4125,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:17:52.794582  5491 maintenance_manager.cc:419] P c7e2815b6eee4d4f842ffb2c29ae19a6: Scheduling MajorDeltaCompactionOp(420432930c7349409e07393d399cd003): perf score=1.000000
I20260812 06:17:52.906804  5298 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.752s	user 1.771s	sys 0.147s
I20260812 06:17:53.015758  5298 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.108s	user 0.001s	sys 0.004s
I20260812 06:17:53.016463  5298 tablet_server.cc:179] TabletServer@127.5.44.129:0 shutting down...
I20260812 06:17:53.029202  5421 maintenance_manager.cc:643] P c7e2815b6eee4d4f842ffb2c29ae19a6: MajorDeltaCompactionOp(420432930c7349409e07393d399cd003) complete. Timing: real 0.234s	user 0.150s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979748,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":502,"lbm_read_time_us":16472,"lbm_reads_lt_1ms":770,"lbm_write_time_us":41365,"lbm_writes_lt_1ms":743,"mutex_wait_us":48,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:17:53.030362  5298 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:53.030797  5298 tablet_replica.cc:333] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6: stopping tablet replica
I20260812 06:17:53.031080  5298 raft_consensus.cc:2243] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:53.031348  5298 raft_consensus.cc:2272] T 420432930c7349409e07393d399cd003 P c7e2815b6eee4d4f842ffb2c29ae19a6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:53.048067  5298 tablet_server.cc:196] TabletServer@127.5.44.129:0 shutdown complete.
I20260812 06:17:53.087656  5298 master.cc:562] Master@127.5.44.190:40659 shutting down...
I20260812 06:17:53.091511  5298 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:53.091699  5298 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:53.091794  5298 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6abc433fb54d4c89b0b0c9a134e80673: stopping tablet replica
I20260812 06:17:53.104074  5298 master.cc:584] Master@127.5.44.190:40659 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5263 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:53.198827  5298 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.44.190:45053
I20260812 06:17:53.199303  5298 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:53.201515  5523 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:53.201577  5526 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:53.201622  5524 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:53.201685  5298 server_base.cc:1061] running on GCE node
I20260812 06:17:53.201869  5298 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:53.201932  5298 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:53.201956  5298 hybrid_clock.cc:648] HybridClock initialized: now 1786515473201956 us; error 0 us; skew 500 ppm
I20260812 06:17:53.202797  5298 webserver.cc:533] Webserver started at http://127.5.44.190:43307/ using document root <none> and password file <none>
I20260812 06:17:53.203111  5298 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:53.203183  5298 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:53.203260  5298 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:53.203650  5298 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/master-0-root/instance:
uuid: "711ff4bc13f3420b9fd9b5f28e097255"
format_stamp: "Formatted at 2026-08-12 06:17:53 on dist-test-slave-7c35"
I20260812 06:17:53.205183  5298 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:53.206123  5531 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:53.206357  5298 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:53.206509  5298 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/master-0-root
uuid: "711ff4bc13f3420b9fd9b5f28e097255"
format_stamp: "Formatted at 2026-08-12 06:17:53 on dist-test-slave-7c35"
I20260812 06:17:53.206610  5298 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-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:53.215433  5298 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:53.215742  5298 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:53.219980  5298 rpc_server.cc:307] RPC server started. Bound to: 127.5.44.190:45053
I20260812 06:17:53.222303  5598 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.44.190:45053 every 8 connection(s)
I20260812 06:17:53.224757  5600 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:53.226462  5600 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255: Bootstrap starting.
I20260812 06:17:53.227223  5600 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:53.228166  5600 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255: No bootstrap required, opened a new log
I20260812 06:17:53.228494  5600 raft_consensus.cc:359] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "711ff4bc13f3420b9fd9b5f28e097255" member_type: VOTER }
I20260812 06:17:53.228572  5600 raft_consensus.cc:385] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:53.228593  5600 raft_consensus.cc:740] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 711ff4bc13f3420b9fd9b5f28e097255, State: Initialized, Role: FOLLOWER
I20260812 06:17:53.228729  5600 consensus_queue.cc:260] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [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: "711ff4bc13f3420b9fd9b5f28e097255" member_type: VOTER }
I20260812 06:17:53.228818  5600 raft_consensus.cc:399] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:53.228842  5600 raft_consensus.cc:493] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:53.228873  5600 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:53.229506  5600 raft_consensus.cc:515] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "711ff4bc13f3420b9fd9b5f28e097255" member_type: VOTER }
I20260812 06:17:53.229611  5600 leader_election.cc:304] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [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: 711ff4bc13f3420b9fd9b5f28e097255; no voters: 
I20260812 06:17:53.229740  5600 leader_election.cc:290] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:53.229902  5604 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:53.230098  5604 raft_consensus.cc:697] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [term 1 LEADER]: Becoming Leader. State: Replica: 711ff4bc13f3420b9fd9b5f28e097255, State: Running, Role: LEADER
I20260812 06:17:53.230257  5600 sys_catalog.cc:565] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:53.230250  5604 consensus_queue.cc:237] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [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: "711ff4bc13f3420b9fd9b5f28e097255" member_type: VOTER }
I20260812 06:17:53.230763  5605 sys_catalog.cc:455] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "711ff4bc13f3420b9fd9b5f28e097255" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "711ff4bc13f3420b9fd9b5f28e097255" member_type: VOTER } }
I20260812 06:17:53.230779  5606 sys_catalog.cc:455] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 711ff4bc13f3420b9fd9b5f28e097255. Latest consensus state: current_term: 1 leader_uuid: "711ff4bc13f3420b9fd9b5f28e097255" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "711ff4bc13f3420b9fd9b5f28e097255" member_type: VOTER } }
I20260812 06:17:53.230880  5605 sys_catalog.cc:458] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:53.230898  5606 sys_catalog.cc:458] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:53.231160  5609 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:53.232045  5609 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:53.232241  5298 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:53.233856  5609 catalog_manager.cc:1383] Generated new cluster ID: 8e993d715f504279a4b998881f6a12fc
I20260812 06:17:53.233922  5609 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:53.271492  5609 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:53.272119  5609 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:53.280027  5609 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255: Generated new TSK 0
I20260812 06:17:53.280213  5609 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:53.296831  5298 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:53.299036  5626 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:53.299072  5622 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:53.299175  5623 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:53.299129  5298 server_base.cc:1061] running on GCE node
I20260812 06:17:53.299434  5298 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:53.299479  5298 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:53.299494  5298 hybrid_clock.cc:648] HybridClock initialized: now 1786515473299494 us; error 0 us; skew 500 ppm
I20260812 06:17:53.300364  5298 webserver.cc:533] Webserver started at http://127.5.44.129:44171/ using document root <none> and password file <none>
I20260812 06:17:53.300545  5298 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:53.300613  5298 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:53.300693  5298 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:53.301108  5298 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/instance:
uuid: "6d544552e86a47d591c7af764115c586"
format_stamp: "Formatted at 2026-08-12 06:17:53 on dist-test-slave-7c35"
I20260812 06:17:53.302644  5298 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:53.303656  5632 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:53.303926  5298 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:53.304020  5298 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root
uuid: "6d544552e86a47d591c7af764115c586"
format_stamp: "Formatted at 2026-08-12 06:17:53 on dist-test-slave-7c35"
I20260812 06:17:53.304095  5298 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-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:53.308956  5298 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:53.309290  5298 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:53.309607  5298 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:53.310046  5298 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:53.310084  5298 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:53.310163  5298 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:53.310201  5298 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:53.314550  5298 rpc_server.cc:307] RPC server started. Bound to: 127.5.44.129:41159
I20260812 06:17:53.316159  5702 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.44.129:41159 every 8 connection(s)
I20260812 06:17:53.324699  5703 heartbeater.cc:344] Connected to a master server at 127.5.44.190:45053
I20260812 06:17:53.324817  5703 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:53.325027  5703 heartbeater.cc:507] Master 127.5.44.190:45053 requested a full tablet report, sending...
I20260812 06:17:53.325644  5554 ts_manager.cc:194] Registered new tserver with Master: 6d544552e86a47d591c7af764115c586 (127.5.44.129:41159)
I20260812 06:17:53.326382  5554 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60062
I20260812 06:17:53.326571  5298 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011078711s
I20260812 06:17:53.333550  5554 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60070:
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:53.341913  5662 tablet_service.cc:1511] Processing CreateTablet for tablet 419e693bc9e441578e1fc54134a20dbe (DEFAULT_TABLE table=heavy-update-compaction-test [id=d4210e6f982d4f40a05334b61105644a]), partition=
I20260812 06:17:53.342188  5662 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 419e693bc9e441578e1fc54134a20dbe. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:53.344340  5717 tablet_bootstrap.cc:492] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Bootstrap starting.
I20260812 06:17:53.345172  5717 tablet_bootstrap.cc:654] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:53.346256  5717 tablet_bootstrap.cc:492] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: No bootstrap required, opened a new log
I20260812 06:17:53.346328  5717 ts_tablet_manager.cc:1403] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:53.346725  5717 raft_consensus.cc:359] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6d544552e86a47d591c7af764115c586" member_type: VOTER last_known_addr { host: "127.5.44.129" port: 41159 } }
I20260812 06:17:53.346848  5717 raft_consensus.cc:385] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:53.346912  5717 raft_consensus.cc:740] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6d544552e86a47d591c7af764115c586, State: Initialized, Role: FOLLOWER
I20260812 06:17:53.347038  5717 consensus_queue.cc:260] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586 [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: "6d544552e86a47d591c7af764115c586" member_type: VOTER last_known_addr { host: "127.5.44.129" port: 41159 } }
I20260812 06:17:53.347143  5717 raft_consensus.cc:399] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:53.347194  5717 raft_consensus.cc:493] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:53.347254  5717 raft_consensus.cc:3060] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:53.348069  5717 raft_consensus.cc:515] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6d544552e86a47d591c7af764115c586" member_type: VOTER last_known_addr { host: "127.5.44.129" port: 41159 } }
I20260812 06:17:53.348208  5717 leader_election.cc:304] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586 [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: 6d544552e86a47d591c7af764115c586; no voters: 
I20260812 06:17:53.348418  5717 leader_election.cc:290] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:53.348537  5719 raft_consensus.cc:2804] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:53.348739  5719 raft_consensus.cc:697] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586 [term 1 LEADER]: Becoming Leader. State: Replica: 6d544552e86a47d591c7af764115c586, State: Running, Role: LEADER
I20260812 06:17:53.348801  5703 heartbeater.cc:499] Master 127.5.44.190:45053 was elected leader, sending a full tablet report...
I20260812 06:17:53.348819  5717 ts_tablet_manager.cc:1434] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:17:53.348927  5719 consensus_queue.cc:237] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586 [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: "6d544552e86a47d591c7af764115c586" member_type: VOTER last_known_addr { host: "127.5.44.129" port: 41159 } }
I20260812 06:17:53.350227  5554 catalog_manager.cc:5719] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586 reported cstate change: term changed from 0 to 1, leader changed from <none> to 6d544552e86a47d591c7af764115c586 (127.5.44.129). New cstate: current_term: 1 leader_uuid: "6d544552e86a47d591c7af764115c586" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6d544552e86a47d591c7af764115c586" member_type: VOTER last_known_addr { host: "127.5.44.129" port: 41159 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:53.408007  5298 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.017s	sys 0.005s
I20260812 06:17:53.566524  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushMRSOp(419e693bc9e441578e1fc54134a20dbe): perf score=23.023690
I20260812 06:17:53.732573  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushMRSOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.166s	user 0.116s	sys 0.048s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1055,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44492,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:17:53.733332  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling LogGCOp(419e693bc9e441578e1fc54134a20dbe): free 20743831 bytes of WAL
I20260812 06:17:53.733626  5637 log_reader.cc:385] T 419e693bc9e441578e1fc54134a20dbe: removed 2 log segments from log reader
I20260812 06:17:53.733695  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000001 (ops 1-6)
I20260812 06:17:53.733748  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000002 (ops 7-11)
I20260812 06:17:53.738545  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: LogGCOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:53.739010  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling UndoDeltaBlockGCOp(419e693bc9e441578e1fc54134a20dbe): 20513823 bytes on disk
I20260812 06:17:53.739456  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: UndoDeltaBlockGCOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:53.739842  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:53.754621  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5503,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.755085  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:53.895933  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.141s	user 0.105s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":413,"lbm_read_time_us":8635,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24328,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6528,"thread_start_us":338,"threads_started":5,"update_count":2000}
I20260812 06:17:53.896615  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=11.118625
I20260812 06:17:53.939347  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.043s	user 0.023s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15768,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:53.939824  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:53.953122  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5062,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:53.953634  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:54.115435  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.162s	user 0.107s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":425,"lbm_read_time_us":10216,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26179,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":75520,"update_count":2000}
I20260812 06:17:54.116086  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=14.095187
I20260812 06:17:54.168133  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.052s	user 0.032s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24248,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.168685  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:54.194967  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.026s	user 0.010s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6730,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.195871  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:54.387544  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.191s	user 0.115s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":173,"lbm_read_time_us":13924,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31015,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:17:54.388290  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=14.095187
I20260812 06:17:54.429652  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.037s	user 0.013s	sys 0.021s Metrics: {"bytes_written":16820139,"delete_count":0,"lbm_write_time_us":16522,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:54.430142  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:54.448673  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.018s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5469,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:54.449165  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:54.615202  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.166s	user 0.124s	sys 0.030s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815667,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":781,"lbm_read_time_us":10293,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31116,"lbm_writes_lt_1ms":543,"mutex_wait_us":326,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:17:54.615829  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=14.095187
I20260812 06:17:54.669441  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.053s	user 0.019s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20654,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.670017  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:54.681936  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4441,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.682456  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:54.852102  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.169s	user 0.116s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":952,"lbm_read_time_us":13068,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31756,"lbm_writes_lt_1ms":543,"mutex_wait_us":256,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:17:54.852787  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=14.095187
I20260812 06:17:54.905767  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.053s	user 0.026s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23628,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.906286  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:54.919884  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4847,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.920463  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushMRSOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:54.950431  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushMRSOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.030s	user 0.024s	sys 0.002s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1344,"drs_written":1,"lbm_read_time_us":34,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1464,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:54.951068  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling LogGCOp(419e693bc9e441578e1fc54134a20dbe): free 115943221 bytes of WAL
I20260812 06:17:54.951318  5637 log_reader.cc:385] T 419e693bc9e441578e1fc54134a20dbe: removed 11 log segments from log reader
I20260812 06:17:54.951397  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000003 (ops 12-16)
I20260812 06:17:54.951438  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000004 (ops 17-21)
I20260812 06:17:54.951476  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000005 (ops 22-26)
I20260812 06:17:54.951501  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000006 (ops 27-31)
I20260812 06:17:54.951535  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000007 (ops 32-36)
I20260812 06:17:54.951565  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000008 (ops 37-41)
I20260812 06:17:54.951589  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000009 (ops 42-46)
I20260812 06:17:54.951625  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000010 (ops 47-51)
I20260812 06:17:54.951660  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000011 (ops 52-56)
I20260812 06:17:54.951690  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000012 (ops 57-61)
I20260812 06:17:54.951719  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000013 (ops 62-66)
I20260812 06:17:54.982030  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: LogGCOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:17:54.982645  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=3.181125
I20260812 06:17:54.995224  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.012s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4828,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:54.995687  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling LogGCOp(419e693bc9e441578e1fc54134a20dbe): free 8767118 bytes of WAL
I20260812 06:17:54.995927  5637 log_reader.cc:385] T 419e693bc9e441578e1fc54134a20dbe: removed 1 log segments from log reader
I20260812 06:17:54.995988  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000014 (ops 67-71)
I20260812 06:17:54.998389  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: LogGCOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:54.998701  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:55.012835  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.014s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5576,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:55.013296  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling UndoDeltaBlockGCOp(419e693bc9e441578e1fc54134a20dbe): 461 bytes on disk
I20260812 06:17:55.013739  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: UndoDeltaBlockGCOp(419e693bc9e441578e1fc54134a20dbe) 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:55.014192  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:55.256681  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.242s	user 0.151s	sys 0.083s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":73,"lbm_read_time_us":14986,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38565,"lbm_writes_lt_1ms":743,"mutex_wait_us":32,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1920,"thread_start_us":72,"threads_started":1,"update_count":3500}
I20260812 06:17:55.257328  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=18.063937
I20260812 06:17:55.337522  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.080s	user 0.050s	sys 0.027s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":30642,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:55.338109  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:55.348390  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3948,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.348807  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:55.543251  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.194s	user 0.150s	sys 0.044s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":315,"lbm_read_time_us":13791,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33180,"lbm_writes_lt_1ms":643,"mutex_wait_us":29,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":3000}
I20260812 06:17:55.543928  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=14.095187
I20260812 06:17:55.592119  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.048s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":20932,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.592597  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:55.608328  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.016s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6206,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.608981  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:55.771618  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.162s	user 0.127s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":157,"lbm_read_time_us":13155,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25744,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:17:55.772313  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=14.095187
I20260812 06:17:55.830581  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.058s	user 0.030s	sys 0.022s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21248,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.831120  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:55.841863  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4297,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.842255  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:56.002635  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.160s	user 0.097s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":954,"lbm_read_time_us":11973,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26417,"lbm_writes_lt_1ms":543,"mutex_wait_us":419,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:17:56.003225  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=11.118625
I20260812 06:17:56.038627  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.035s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15538,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:56.039314  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:56.066717  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.027s	user 0.008s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5389,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:56.067510  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:56.224217  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.157s	user 0.105s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713265,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":909,"lbm_read_time_us":11002,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23575,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2000}
I20260812 06:17:56.224799  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=14.095187
I20260812 06:17:56.271026  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.046s	user 0.026s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18369,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:56.271555  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:56.282552  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3798,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.283080  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:56.431766  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.149s	user 0.108s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1112,"lbm_read_time_us":9518,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32736,"lbm_writes_lt_1ms":543,"mutex_wait_us":258,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":82944,"update_count":2500}
I20260812 06:17:56.432474  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=11.118625
I20260812 06:17:56.476284  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.044s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18013,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:56.476958  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:56.499641  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.023s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4550,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:56.500151  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:56.509979  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.010s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3848,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.510556  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushMRSOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:56.542903  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushMRSOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.032s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":49,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1530,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1690,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:56.543661  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling LogGCOp(419e693bc9e441578e1fc54134a20dbe): free 120553332 bytes of WAL
I20260812 06:17:56.543905  5637 log_reader.cc:385] T 419e693bc9e441578e1fc54134a20dbe: removed 12 log segments from log reader
I20260812 06:17:56.543969  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000015 (ops 72-76)
I20260812 06:17:56.544025  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000016 (ops 77-80)
I20260812 06:17:56.544062  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000017 (ops 81-85)
I20260812 06:17:56.544100  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000018 (ops 86-90)
I20260812 06:17:56.544137  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000019 (ops 91-94)
I20260812 06:17:56.544174  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000020 (ops 95-99)
I20260812 06:17:56.544211  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000021 (ops 100-104)
I20260812 06:17:56.544247  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000022 (ops 105-109)
I20260812 06:17:56.544286  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000023 (ops 110-114)
I20260812 06:17:56.544320  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000024 (ops 115-119)
I20260812 06:17:56.544356  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000025 (ops 120-124)
I20260812 06:17:56.544392  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000026 (ops 125-129)
I20260812 06:17:56.569911  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: LogGCOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:56.570310  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=4.173312
I20260812 06:17:56.587939  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.017s	user 0.004s	sys 0.013s Metrics: {"bytes_written":6235917,"delete_count":0,"lbm_write_time_us":7432,"lbm_writes_lt_1ms":155,"reinsert_count":0,"update_count":760}
I20260812 06:17:56.588354  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling LogGCOp(419e693bc9e441578e1fc54134a20dbe): free 12018006 bytes of WAL
I20260812 06:17:56.588543  5637 log_reader.cc:385] T 419e693bc9e441578e1fc54134a20dbe: removed 1 log segments from log reader
I20260812 06:17:56.588583  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000027 (ops 130-134)
I20260812 06:17:56.590803  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: LogGCOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:56.591221  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:56.599897  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.008s	user 0.005s	sys 0.002s Metrics: {"bytes_written":1969352,"delete_count":0,"lbm_write_time_us":2451,"lbm_writes_lt_1ms":51,"reinsert_count":0,"update_count":240}
I20260812 06:17:56.600312  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling UndoDeltaBlockGCOp(419e693bc9e441578e1fc54134a20dbe): 482 bytes on disk
I20260812 06:17:56.600754  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: UndoDeltaBlockGCOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:17:56.601250  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:56.826723  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.225s	user 0.137s	sys 0.085s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020802,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":280,"lbm_read_time_us":14714,"lbm_reads_lt_1ms":775,"lbm_write_time_us":36184,"lbm_writes_lt_1ms":743,"mutex_wait_us":19,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14464,"thread_start_us":72,"threads_started":1,"update_count":3500}
I20260812 06:17:56.827414  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=18.063937
I20260812 06:17:56.890992  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.063s	user 0.033s	sys 0.031s Metrics: {"bytes_written":20512321,"delete_count":0,"lbm_write_time_us":23537,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:56.891477  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:56.909734  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.018s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5954,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.910292  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:57.118374  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.208s	user 0.152s	sys 0.056s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918103,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":875,"lbm_read_time_us":12720,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34077,"lbm_writes_lt_1ms":643,"mutex_wait_us":240,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3000}
I20260812 06:17:57.119047  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=18.063937
I20260812 06:17:57.185268  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.066s	user 0.032s	sys 0.021s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":24895,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:57.185729  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:57.195605  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3738,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.196225  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:57.401670  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.205s	user 0.148s	sys 0.054s 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":649,"lbm_read_time_us":12590,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33514,"lbm_writes_lt_1ms":643,"mutex_wait_us":304,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":3000}
I20260812 06:17:57.402372  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=16.079562
I20260812 06:17:57.466235  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.064s	user 0.031s	sys 0.019s Metrics: {"bytes_written":18132915,"delete_count":0,"lbm_write_time_us":24096,"lbm_writes_lt_1ms":445,"reinsert_count":0,"update_count":2210}
I20260812 06:17:57.466693  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=5.165500
I20260812 06:17:57.483776  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":6482069,"delete_count":0,"lbm_write_time_us":6937,"lbm_writes_lt_1ms":161,"reinsert_count":0,"update_count":790}
I20260812 06:17:57.484292  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:57.697993  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.214s	user 0.132s	sys 0.077s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":156,"lbm_read_time_us":12890,"lbm_reads_lt_1ms":672,"lbm_write_time_us":38194,"lbm_writes_lt_1ms":643,"mutex_wait_us":38,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":3000}
I20260812 06:17:57.698755  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=18.063937
I20260812 06:17:57.764724  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.066s	user 0.047s	sys 0.016s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":29059,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:57.765209  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:57.782572  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6711,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.783213  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:58.006247  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.223s	user 0.152s	sys 0.060s 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":162,"lbm_read_time_us":14935,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37399,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":3000}
I20260812 06:17:58.007241  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=18.063937
I20260812 06:17:58.068074  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.061s	user 0.041s	sys 0.017s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26437,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:58.068540  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:58.079327  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3862,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.079792  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushMRSOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:58.107039  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushMRSOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.027s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":313,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":1348,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1536,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:58.107856  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling LogGCOp(419e693bc9e441578e1fc54134a20dbe): free 121459768 bytes of WAL
I20260812 06:17:58.108099  5637 log_reader.cc:385] T 419e693bc9e441578e1fc54134a20dbe: removed 12 log segments from log reader
I20260812 06:17:58.108170  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000028 (ops 135-139)
I20260812 06:17:58.108218  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000029 (ops 140-144)
I20260812 06:17:58.108255  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000030 (ops 145-149)
I20260812 06:17:58.108294  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000031 (ops 150-154)
I20260812 06:17:58.108335  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000032 (ops 155-159)
I20260812 06:17:58.108374  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000033 (ops 160-164)
I20260812 06:17:58.108415  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000034 (ops 165-169)
I20260812 06:17:58.108453  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000035 (ops 170-174)
I20260812 06:17:58.108493  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000036 (ops 175-179)
I20260812 06:17:58.108533  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000037 (ops 180-184)
I20260812 06:17:58.108572  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000038 (ops 185-189)
I20260812 06:17:58.108613  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000039 (ops 190-194)
I20260812 06:17:58.135018  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: LogGCOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:58.135483  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling UndoDeltaBlockGCOp(419e693bc9e441578e1fc54134a20dbe): 493 bytes on disk
I20260812 06:17:58.136011  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: UndoDeltaBlockGCOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:17:58.136559  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=3.181125
I20260812 06:17:58.148712  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":5005191,"delete_count":0,"lbm_write_time_us":4822,"lbm_writes_lt_1ms":125,"reinsert_count":0,"update_count":610}
I20260812 06:17:58.149088  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling LogGCOp(419e693bc9e441578e1fc54134a20dbe): free 11564893 bytes of WAL
I20260812 06:17:58.149277  5637 log_reader.cc:385] T 419e693bc9e441578e1fc54134a20dbe: removed 1 log segments from log reader
I20260812 06:17:58.149318  5637 log.cc:1079] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: Deleting log segment in path: /tmp/dist-test-taskF9p2n9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467913499-5298-0/minicluster-data/ts-0-root/wals/419e693bc9e441578e1fc54134a20dbe/wal-000000040 (ops 195-198)
I20260812 06:17:58.151762  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: LogGCOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:58.152045  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe): perf score=2.188937
I20260812 06:17:58.160364  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: FlushDeltaMemStoresOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.008s	user 0.002s	sys 0.005s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":3041,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:17:58.160741  5704 maintenance_manager.cc:419] P 6d544552e86a47d591c7af764115c586: Scheduling MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe): perf score=1.000000
I20260812 06:17:58.189620  5298 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.782s	user 1.783s	sys 0.168s
I20260812 06:17:58.284215  5298 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.094s	user 0.003s	sys 0.000s
I20260812 06:17:58.284832  5298 tablet_server.cc:179] TabletServer@127.5.44.129:0 shutting down...
I20260812 06:17:58.362090  5637 maintenance_manager.cc:643] P 6d544552e86a47d591c7af764115c586: MajorDeltaCompactionOp(419e693bc9e441578e1fc54134a20dbe) complete. Timing: real 0.201s	user 0.149s	sys 0.052s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37123137,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":373,"lbm_read_time_us":16148,"lbm_reads_lt_1ms":870,"lbm_write_time_us":36386,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":4992,"thread_start_us":80,"threads_started":1,"update_count":4000}
I20260812 06:17:58.363565  5298 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:58.363783  5298 tablet_replica.cc:333] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586: stopping tablet replica
I20260812 06:17:58.363924  5298 raft_consensus.cc:2243] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:58.364101  5298 raft_consensus.cc:2272] T 419e693bc9e441578e1fc54134a20dbe P 6d544552e86a47d591c7af764115c586 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:58.368446  5298 tablet_server.cc:196] TabletServer@127.5.44.129:0 shutdown complete.
I20260812 06:17:58.435153  5298 master.cc:562] Master@127.5.44.190:45053 shutting down...
I20260812 06:17:58.438198  5298 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:58.438381  5298 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:58.438474  5298 tablet_replica.cc:333] T 00000000000000000000000000000000 P 711ff4bc13f3420b9fd9b5f28e097255: stopping tablet replica
I20260812 06:17:58.450786  5298 master.cc:584] Master@127.5.44.190:45053 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5342 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10606 ms total)

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