[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:42.813444 27598 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.243.190:40903
I20260812 06:18:42.814425 27598 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:42.815003 27598 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:42.821396 27605 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:42.821431 27598 server_base.cc:1061] running on GCE node
W20260812 06:18:42.821609 27604 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:42.821717 27609 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:42.822162 27598 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:42.822305 27598 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:42.822364 27598 hybrid_clock.cc:648] HybridClock initialized: now 1786515522822361 us; error 0 us; skew 500 ppm
I20260812 06:18:42.824043 27598 webserver.cc:533] Webserver started at http://127.26.243.190:37519/ using document root <none> and password file <none>
I20260812 06:18:42.824605 27598 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:42.824692 27598 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:42.824934 27598 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:42.826498 27598 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/master-0-root/instance:
uuid: "9feb5a5741334fab93bd92d81b89a730"
format_stamp: "Formatted at 2026-08-12 06:18:42 on dist-test-slave-rwrg"
I20260812 06:18:42.829823 27598 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:42.831765 27615 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:42.832746 27598 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:42.832872 27598 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/master-0-root
uuid: "9feb5a5741334fab93bd92d81b89a730"
format_stamp: "Formatted at 2026-08-12 06:18:42 on dist-test-slave-rwrg"
I20260812 06:18:42.832973 27598 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:42.845270 27598 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:42.845832 27598 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:42.846006 27598 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:42.853024 27598 rpc_server.cc:307] RPC server started. Bound to: 127.26.243.190:40903
I20260812 06:18:42.853030 27710 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.243.190:40903 every 8 connection(s)
I20260812 06:18:42.855077 27712 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:42.859957 27712 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730: Bootstrap starting.
I20260812 06:18:42.862221 27712 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:42.863085 27712 log.cc:826] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:42.864625 27712 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730: No bootstrap required, opened a new log
I20260812 06:18:42.867229 27712 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9feb5a5741334fab93bd92d81b89a730" member_type: VOTER }
I20260812 06:18:42.867420 27712 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:42.867518 27712 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9feb5a5741334fab93bd92d81b89a730, State: Initialized, Role: FOLLOWER
I20260812 06:18:42.868139 27712 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [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: "9feb5a5741334fab93bd92d81b89a730" member_type: VOTER }
I20260812 06:18:42.868343 27712 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:42.868439 27712 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:42.868587 27712 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:42.869378 27712 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9feb5a5741334fab93bd92d81b89a730" member_type: VOTER }
I20260812 06:18:42.869823 27712 leader_election.cc:304] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [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: 9feb5a5741334fab93bd92d81b89a730; no voters: 
I20260812 06:18:42.870138 27712 leader_election.cc:290] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:42.870296 27715 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:42.870555 27715 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [term 1 LEADER]: Becoming Leader. State: Replica: 9feb5a5741334fab93bd92d81b89a730, State: Running, Role: LEADER
I20260812 06:18:42.870954 27715 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [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: "9feb5a5741334fab93bd92d81b89a730" member_type: VOTER }
I20260812 06:18:42.871066 27712 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:42.872676 27717 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9feb5a5741334fab93bd92d81b89a730" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9feb5a5741334fab93bd92d81b89a730" member_type: VOTER } }
I20260812 06:18:42.872792 27717 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:42.873096 27719 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9feb5a5741334fab93bd92d81b89a730. Latest consensus state: current_term: 1 leader_uuid: "9feb5a5741334fab93bd92d81b89a730" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9feb5a5741334fab93bd92d81b89a730" member_type: VOTER } }
I20260812 06:18:42.873175 27719 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:42.873162 27731 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:42.873394 27598 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:42.875419 27731 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:42.879912 27731 catalog_manager.cc:1383] Generated new cluster ID: 7900ea3811a348998f7db6cd2831364b
I20260812 06:18:42.879987 27731 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:42.896808 27731 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:42.897591 27731 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:42.905746 27731 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730: Generated new TSK 0
I20260812 06:18:42.906351 27731 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:42.938052 27598 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:42.940770 27752 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:42.940869 27749 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:42.940984 27750 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:42.941112 27598 server_base.cc:1061] running on GCE node
I20260812 06:18:42.941284 27598 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:42.941331 27598 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:42.941351 27598 hybrid_clock.cc:648] HybridClock initialized: now 1786515522941352 us; error 0 us; skew 500 ppm
I20260812 06:18:42.942243 27598 webserver.cc:533] Webserver started at http://127.26.243.129:40705/ using document root <none> and password file <none>
I20260812 06:18:42.942402 27598 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:42.942461 27598 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:42.942548 27598 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:42.942975 27598 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/instance:
uuid: "7d4bb61d8ead46a9a8c24a4fddb96edb"
format_stamp: "Formatted at 2026-08-12 06:18:42 on dist-test-slave-rwrg"
I20260812 06:18:42.944797 27598 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:42.945870 27759 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:42.946154 27598 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:42.946223 27598 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root
uuid: "7d4bb61d8ead46a9a8c24a4fddb96edb"
format_stamp: "Formatted at 2026-08-12 06:18:42 on dist-test-slave-rwrg"
I20260812 06:18:42.946309 27598 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:42.955308 27598 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:42.955693 27598 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:42.956163 27598 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:42.957010 27598 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:42.957060 27598 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:42.957124 27598 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:42.957168 27598 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:42.964010 27598 rpc_server.cc:307] RPC server started. Bound to: 127.26.243.129:42973
I20260812 06:18:42.964056 27879 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.243.129:42973 every 8 connection(s)
I20260812 06:18:42.974148 27880 heartbeater.cc:344] Connected to a master server at 127.26.243.190:40903
I20260812 06:18:42.974342 27880 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:42.974728 27880 heartbeater.cc:507] Master 127.26.243.190:40903 requested a full tablet report, sending...
I20260812 06:18:42.976024 27649 ts_manager.cc:194] Registered new tserver with Master: 7d4bb61d8ead46a9a8c24a4fddb96edb (127.26.243.129:42973)
I20260812 06:18:42.976917 27598 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012287425s
I20260812 06:18:42.977414 27649 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57260
I20260812 06:18:42.985687 27649 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57276:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:42.998471 27819 tablet_service.cc:1511] Processing CreateTablet for tablet 314b568908c043b9814b9eb61c56d303 (DEFAULT_TABLE table=heavy-update-compaction-test [id=7c66759ac6b2450483a39b79b5c1e089]), partition=
I20260812 06:18:42.998884 27819 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 314b568908c043b9814b9eb61c56d303. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:43.001253 27910 tablet_bootstrap.cc:492] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Bootstrap starting.
I20260812 06:18:43.002213 27910 tablet_bootstrap.cc:654] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:43.003479 27910 tablet_bootstrap.cc:492] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: No bootstrap required, opened a new log
I20260812 06:18:43.003561 27910 ts_tablet_manager.cc:1403] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:43.004006 27910 raft_consensus.cc:359] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7d4bb61d8ead46a9a8c24a4fddb96edb" member_type: VOTER last_known_addr { host: "127.26.243.129" port: 42973 } }
I20260812 06:18:43.004101 27910 raft_consensus.cc:385] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:43.004125 27910 raft_consensus.cc:740] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7d4bb61d8ead46a9a8c24a4fddb96edb, State: Initialized, Role: FOLLOWER
I20260812 06:18:43.004281 27910 consensus_queue.cc:260] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb [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: "7d4bb61d8ead46a9a8c24a4fddb96edb" member_type: VOTER last_known_addr { host: "127.26.243.129" port: 42973 } }
I20260812 06:18:43.004372 27910 raft_consensus.cc:399] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:43.004420 27910 raft_consensus.cc:493] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:43.004477 27910 raft_consensus.cc:3060] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:43.005201 27910 raft_consensus.cc:515] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7d4bb61d8ead46a9a8c24a4fddb96edb" member_type: VOTER last_known_addr { host: "127.26.243.129" port: 42973 } }
I20260812 06:18:43.005362 27910 leader_election.cc:304] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb [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: 7d4bb61d8ead46a9a8c24a4fddb96edb; no voters: 
I20260812 06:18:43.005613 27910 leader_election.cc:290] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:43.005707 27913 raft_consensus.cc:2804] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:43.005930 27913 raft_consensus.cc:697] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb [term 1 LEADER]: Becoming Leader. State: Replica: 7d4bb61d8ead46a9a8c24a4fddb96edb, State: Running, Role: LEADER
I20260812 06:18:43.005996 27910 ts_tablet_manager.cc:1434] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:43.006160 27913 consensus_queue.cc:237] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb [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: "7d4bb61d8ead46a9a8c24a4fddb96edb" member_type: VOTER last_known_addr { host: "127.26.243.129" port: 42973 } }
I20260812 06:18:43.006480 27880 heartbeater.cc:499] Master 127.26.243.190:40903 was elected leader, sending a full tablet report...
I20260812 06:18:43.009318 27649 catalog_manager.cc:5719] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb reported cstate change: term changed from 0 to 1, leader changed from <none> to 7d4bb61d8ead46a9a8c24a4fddb96edb (127.26.243.129). New cstate: current_term: 1 leader_uuid: "7d4bb61d8ead46a9a8c24a4fddb96edb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7d4bb61d8ead46a9a8c24a4fddb96edb" member_type: VOTER last_known_addr { host: "127.26.243.129" port: 42973 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:43.076989 27598 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.023s	sys 0.011s
I20260812 06:18:43.215197 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushMRSOp(314b568908c043b9814b9eb61c56d303): perf score=19.054940
I20260812 06:18:43.387698 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushMRSOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.172s	user 0.132s	sys 0.032s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":502,"delete_count":0,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":946,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43423,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":204,"threads_started":1,"update_count":1500}
I20260812 06:18:43.388749 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling LogGCOp(314b568908c043b9814b9eb61c56d303): free 20290830 bytes of WAL
I20260812 06:18:43.389060 27770 log_reader.cc:385] T 314b568908c043b9814b9eb61c56d303: removed 2 log segments from log reader
I20260812 06:18:43.389148 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000001 (ops 1-6)
I20260812 06:18:43.389245 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000002 (ops 7-10)
I20260812 06:18:43.393440 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: LogGCOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:43.393743 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:43.410838 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.017s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6026,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.411345 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling UndoDeltaBlockGCOp(314b568908c043b9814b9eb61c56d303): 16411391 bytes on disk
I20260812 06:18:43.411983 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: UndoDeltaBlockGCOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:18:43.412393 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:43.562907 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.150s	user 0.097s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1998,"lbm_read_time_us":9242,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22767,"lbm_writes_lt_1ms":443,"mutex_wait_us":800,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":400,"threads_started":5,"update_count":2000}
I20260812 06:18:43.563635 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=10.126437
I20260812 06:18:43.617170 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.053s	user 0.022s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17961,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:43.617890 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=3.181125
I20260812 06:18:43.635164 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":6784,"lbm_writes_lt_1ms":113,"reinsert_count":0,"spinlock_wait_cycles":26880,"update_count":550}
I20260812 06:18:43.635598 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:43.644809 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3390,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:43.645208 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:43.790796 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.145s	user 0.115s	sys 0.030s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774797,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":940,"lbm_read_time_us":9156,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31060,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":93056,"update_count":2500}
I20260812 06:18:43.791393 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=10.126437
I20260812 06:18:43.831719 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.040s	user 0.022s	sys 0.013s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15958,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:43.832204 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:43.842476 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4140,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.842856 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:43.962061 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.119s	user 0.095s	sys 0.024s 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":263,"lbm_read_time_us":9509,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21487,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:18:43.962682 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=10.126437
I20260812 06:18:44.013967 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.051s	user 0.027s	sys 0.015s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16189,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:44.014482 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:44.025712 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4439,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.026161 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:44.175644 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.149s	user 0.107s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":674,"lbm_read_time_us":10288,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25260,"lbm_writes_lt_1ms":443,"mutex_wait_us":62,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:18:44.176360 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=10.126437
I20260812 06:18:44.220887 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.044s	user 0.020s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15288,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:44.221351 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:44.231598 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4123,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.232033 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:44.357098 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.125s	user 0.099s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1061,"lbm_read_time_us":9249,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24496,"lbm_writes_lt_1ms":443,"mutex_wait_us":286,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22784,"update_count":2000}
I20260812 06:18:44.357609 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=10.126437
I20260812 06:18:44.398465 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.041s	user 0.028s	sys 0.010s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17091,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:44.398962 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:44.414131 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.414618 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:44.532606 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.116s	user 0.096s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":988,"lbm_read_time_us":7074,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21807,"lbm_writes_lt_1ms":443,"mutex_wait_us":460,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2000}
I20260812 06:18:44.533390 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=10.126437
I20260812 06:18:44.572198 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.039s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14178,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:44.572813 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:44.587834 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5743,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.588402 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushMRSOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:44.615677 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushMRSOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":1218,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1588,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:44.616454 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling LogGCOp(314b568908c043b9814b9eb61c56d303): free 121006424 bytes of WAL
I20260812 06:18:44.616791 27770 log_reader.cc:385] T 314b568908c043b9814b9eb61c56d303: removed 12 log segments from log reader
I20260812 06:18:44.616858 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000003 (ops 11-15)
I20260812 06:18:44.616894 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000004 (ops 16-20)
I20260812 06:18:44.616921 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000005 (ops 21-25)
I20260812 06:18:44.616971 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000006 (ops 26-30)
I20260812 06:18:44.616994 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000007 (ops 31-35)
I20260812 06:18:44.617023 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000008 (ops 36-40)
I20260812 06:18:44.617050 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000009 (ops 41-45)
I20260812 06:18:44.617081 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000010 (ops 46-50)
I20260812 06:18:44.617116 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000011 (ops 51-54)
I20260812 06:18:44.617146 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000012 (ops 55-59)
I20260812 06:18:44.617177 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000013 (ops 60-64)
I20260812 06:18:44.617205 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000014 (ops 65-69)
I20260812 06:18:44.644593 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: LogGCOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.028s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:44.644964 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:44.666534 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.021s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4590,"lbm_writes_lt_1ms":103,"mutex_wait_us":65,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.666967 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling UndoDeltaBlockGCOp(314b568908c043b9814b9eb61c56d303): 462 bytes on disk
I20260812 06:18:44.667397 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: UndoDeltaBlockGCOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:18:44.667845 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:44.682412 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5385,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.682966 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:44.852078 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.169s	user 0.129s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":493,"lbm_read_time_us":10734,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34324,"lbm_writes_lt_1ms":643,"mutex_wait_us":46,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8960,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:18:44.852711 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=14.095187
I20260812 06:18:44.902875 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.050s	user 0.025s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18533,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:44.903386 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:44.914969 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4450,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.915449 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:45.082751 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.167s	user 0.133s	sys 0.023s 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":645,"lbm_read_time_us":10786,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30991,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":57472,"update_count":2500}
I20260812 06:18:45.083420 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=14.095187
I20260812 06:18:45.137389 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.054s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23760,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:45.137861 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:45.149115 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3999,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.149574 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:45.322438 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.173s	user 0.133s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":885,"lbm_read_time_us":11082,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30298,"lbm_writes_lt_1ms":543,"mutex_wait_us":276,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2500}
I20260812 06:18:45.323163 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=14.095187
I20260812 06:18:45.380329 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.057s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20112,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:45.380818 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:45.391396 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4154,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.391844 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:45.578500 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.186s	user 0.118s	sys 0.056s 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":369,"lbm_read_time_us":12768,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31065,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:18:45.579238 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=14.095187
I20260812 06:18:45.633270 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.054s	user 0.047s	sys 0.000s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19346,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:45.633790 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:45.644320 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4187,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.644820 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:45.820657 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.176s	user 0.109s	sys 0.058s 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":628,"lbm_read_time_us":12895,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27111,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:18:45.821188 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=14.095187
I20260812 06:18:45.886075 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.065s	user 0.039s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25127,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:45.886579 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:45.897228 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4122,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.897651 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:46.069384 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.172s	user 0.119s	sys 0.052s 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":291,"lbm_read_time_us":12268,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28542,"lbm_writes_lt_1ms":543,"mutex_wait_us":68,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:18:46.072959 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=10.126437
I20260812 06:18:46.108592 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.035s	user 0.032s	sys 0.004s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15586,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:46.109108 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:46.127192 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.018s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5802,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.127734 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushMRSOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:46.176146 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushMRSOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.048s	user 0.034s	sys 0.001s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":49,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1354,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2210,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:46.176898 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling LogGCOp(314b568908c043b9814b9eb61c56d303): free 124257248 bytes of WAL
I20260812 06:18:46.177255 27770 log_reader.cc:385] T 314b568908c043b9814b9eb61c56d303: removed 12 log segments from log reader
I20260812 06:18:46.177343 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000015 (ops 70-74)
I20260812 06:18:46.177394 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000016 (ops 75-79)
I20260812 06:18:46.177436 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000017 (ops 80-84)
I20260812 06:18:46.177467 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000018 (ops 85-89)
I20260812 06:18:46.177505 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000019 (ops 90-94)
I20260812 06:18:46.177541 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000020 (ops 95-99)
I20260812 06:18:46.177582 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000021 (ops 100-104)
I20260812 06:18:46.177623 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000022 (ops 105-109)
I20260812 06:18:46.177706 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000023 (ops 110-114)
I20260812 06:18:46.177754 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000024 (ops 115-118)
I20260812 06:18:46.177785 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000025 (ops 119-123)
I20260812 06:18:46.177824 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000026 (ops 124-128)
I20260812 06:18:46.203832 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: LogGCOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.027s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:46.204265 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling UndoDeltaBlockGCOp(314b568908c043b9814b9eb61c56d303): 493 bytes on disk
I20260812 06:18:46.204775 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: UndoDeltaBlockGCOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:18:46.205276 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=6.157687
I20260812 06:18:46.232857 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.027s	user 0.016s	sys 0.011s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11798,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:46.233301 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling LogGCOp(314b568908c043b9814b9eb61c56d303): free 8767138 bytes of WAL
I20260812 06:18:46.233515 27770 log_reader.cc:385] T 314b568908c043b9814b9eb61c56d303: removed 1 log segments from log reader
I20260812 06:18:46.233561 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000027 (ops 129-133)
I20260812 06:18:46.235379 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: LogGCOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:46.235672 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:46.448334 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.212s	user 0.124s	sys 0.076s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877222,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":676,"lbm_read_time_us":11819,"lbm_reads_lt_1ms":665,"lbm_write_time_us":34159,"lbm_writes_lt_1ms":643,"mutex_wait_us":66,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:18:46.449172 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=18.063937
I20260812 06:18:46.511085 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.062s	user 0.038s	sys 0.019s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26682,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:46.511597 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:46.522325 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3901,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.522959 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:46.722471 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.199s	user 0.132s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":158,"lbm_read_time_us":12880,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35383,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":3000}
I20260812 06:18:46.723310 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=15.087375
I20260812 06:18:46.777798 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.054s	user 0.021s	sys 0.032s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":24540,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:46.778452 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:46.791369 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4577,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:46.791924 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:46.960588 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.168s	user 0.113s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":125,"lbm_read_time_us":12535,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29622,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:18:46.961211 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=14.095187
I20260812 06:18:47.019326 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.058s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19515,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:47.019866 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:47.031086 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4368,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.031508 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:47.197697 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.166s	user 0.112s	sys 0.051s 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":310,"lbm_read_time_us":11763,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27162,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:47.198410 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=11.118625
I20260812 06:18:47.241420 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.043s	user 0.030s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17871,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:47.242106 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:47.270697 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.028s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4833,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:47.271319 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:47.282765 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4342,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.283442 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:47.445942 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.162s	user 0.115s	sys 0.047s 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":682,"lbm_read_time_us":11513,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28167,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:47.446664 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=14.095187
I20260812 06:18:47.501354 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.054s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22215,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:47.501971 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:47.522536 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.020s	user 0.011s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.523124 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:47.702473 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.179s	user 0.124s	sys 0.047s 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":511,"lbm_read_time_us":11675,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27786,"lbm_writes_lt_1ms":543,"mutex_wait_us":84,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:18:47.703187 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=14.095187
I20260812 06:18:47.756480 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.052s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24523,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:47.757056 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:47.773464 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.016s	user 0.005s	sys 0.010s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6699,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.774256 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushMRSOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:47.811898 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushMRSOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.037s	user 0.022s	sys 0.009s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":1335,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2211,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:47.812707 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling LogGCOp(314b568908c043b9814b9eb61c56d303): free 132571590 bytes of WAL
I20260812 06:18:47.812968 27770 log_reader.cc:385] T 314b568908c043b9814b9eb61c56d303: removed 13 log segments from log reader
I20260812 06:18:47.813032 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000028 (ops 134-138)
I20260812 06:18:47.813072 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000029 (ops 139-143)
I20260812 06:18:47.813105 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000030 (ops 144-148)
I20260812 06:18:47.813134 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000031 (ops 149-153)
I20260812 06:18:47.813161 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000032 (ops 154-158)
I20260812 06:18:47.813189 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000033 (ops 159-163)
I20260812 06:18:47.813218 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000034 (ops 164-168)
I20260812 06:18:47.813251 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000035 (ops 169-173)
I20260812 06:18:47.813274 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000036 (ops 174-178)
I20260812 06:18:47.813300 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000037 (ops 179-182)
I20260812 06:18:47.813328 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000038 (ops 183-187)
I20260812 06:18:47.813356 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000039 (ops 188-192)
I20260812 06:18:47.813390 27770 log.cc:1079] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/314b568908c043b9814b9eb61c56d303/wal-000000040 (ops 193-196)
I20260812 06:18:47.846082 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: LogGCOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.033s	user 0.004s	sys 0.028s Metrics: {}
I20260812 06:18:47.846511 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling UndoDeltaBlockGCOp(314b568908c043b9814b9eb61c56d303): 492 bytes on disk
I20260812 06:18:47.847054 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: UndoDeltaBlockGCOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4}
I20260812 06:18:47.847580 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=3.181125
I20260812 06:18:47.867203 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.019s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7422,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:47.867614 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303): perf score=2.188937
I20260812 06:18:47.877321 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: FlushDeltaMemStoresOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3772,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:47.877857 27881 maintenance_manager.cc:419] P 7d4bb61d8ead46a9a8c24a4fddb96edb: Scheduling MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303): perf score=1.000000
I20260812 06:18:47.915931 27598 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.839s	user 1.863s	sys 0.115s
I20260812 06:18:48.010960 27598 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.094s	user 0.001s	sys 0.000s
I20260812 06:18:48.011602 27598 tablet_server.cc:179] TabletServer@127.26.243.129:0 shutting down...
I20260812 06:18:48.067590 27770 maintenance_manager.cc:643] P 7d4bb61d8ead46a9a8c24a4fddb96edb: MajorDeltaCompactionOp(314b568908c043b9814b9eb61c56d303) complete. Timing: real 0.190s	user 0.135s	sys 0.054s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979739,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":965,"lbm_read_time_us":14260,"lbm_reads_lt_1ms":770,"lbm_write_time_us":33238,"lbm_writes_lt_1ms":743,"mutex_wait_us":283,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":20608,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:18:48.068658 27598 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:48.069120 27598 tablet_replica.cc:333] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb: stopping tablet replica
I20260812 06:18:48.069365 27598 raft_consensus.cc:2243] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:48.069610 27598 raft_consensus.cc:2272] T 314b568908c043b9814b9eb61c56d303 P 7d4bb61d8ead46a9a8c24a4fddb96edb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:48.085378 27598 tablet_server.cc:196] TabletServer@127.26.243.129:0 shutdown complete.
I20260812 06:18:48.125128 27598 master.cc:562] Master@127.26.243.190:40903 shutting down...
I20260812 06:18:48.129310 27598 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:48.129510 27598 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:48.129602 27598 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9feb5a5741334fab93bd92d81b89a730: stopping tablet replica
I20260812 06:18:48.142028 27598 master.cc:584] Master@127.26.243.190:40903 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5410 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:48.234397 27598 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.243.190:34401
I20260812 06:18:48.234812 27598 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:48.237146 27598 server_base.cc:1061] running on GCE node
W20260812 06:18:48.237176 27951 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:48.237293 27949 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:48.237237 27945 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:48.237584 27598 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:48.237629 27598 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:48.237649 27598 hybrid_clock.cc:648] HybridClock initialized: now 1786515528237649 us; error 0 us; skew 500 ppm
I20260812 06:18:48.238495 27598 webserver.cc:533] Webserver started at http://127.26.243.190:35659/ using document root <none> and password file <none>
I20260812 06:18:48.238660 27598 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:48.238703 27598 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:48.238803 27598 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:48.239174 27598 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/master-0-root/instance:
uuid: "adc3117588ce49e099e2bddfe3cdbe05"
format_stamp: "Formatted at 2026-08-12 06:18:48 on dist-test-slave-rwrg"
I20260812 06:18:48.240603 27598 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:48.241506 27965 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:48.241789 27598 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:48.241890 27598 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/master-0-root
uuid: "adc3117588ce49e099e2bddfe3cdbe05"
format_stamp: "Formatted at 2026-08-12 06:18:48 on dist-test-slave-rwrg"
I20260812 06:18:48.241987 27598 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:48.260252 27598 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:48.260726 27598 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:48.265108 27598 rpc_server.cc:307] RPC server started. Bound to: 127.26.243.190:34401
I20260812 06:18:48.267561 28054 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.243.190:34401 every 8 connection(s)
I20260812 06:18:48.271513 28058 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:48.274019 28058 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05: Bootstrap starting.
I20260812 06:18:48.274811 28058 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:48.275806 28058 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05: No bootstrap required, opened a new log
I20260812 06:18:48.276170 28058 raft_consensus.cc:359] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adc3117588ce49e099e2bddfe3cdbe05" member_type: VOTER }
I20260812 06:18:48.276254 28058 raft_consensus.cc:385] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:48.276276 28058 raft_consensus.cc:740] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: adc3117588ce49e099e2bddfe3cdbe05, State: Initialized, Role: FOLLOWER
I20260812 06:18:48.276386 28058 consensus_queue.cc:260] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [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: "adc3117588ce49e099e2bddfe3cdbe05" member_type: VOTER }
I20260812 06:18:48.276443 28058 raft_consensus.cc:399] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:48.276463 28058 raft_consensus.cc:493] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:48.276551 28058 raft_consensus.cc:3060] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:48.277192 28058 raft_consensus.cc:515] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adc3117588ce49e099e2bddfe3cdbe05" member_type: VOTER }
I20260812 06:18:48.277303 28058 leader_election.cc:304] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [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: adc3117588ce49e099e2bddfe3cdbe05; no voters: 
I20260812 06:18:48.277444 28058 leader_election.cc:290] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:48.277643 28061 raft_consensus.cc:2804] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:48.277881 28061 raft_consensus.cc:697] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [term 1 LEADER]: Becoming Leader. State: Replica: adc3117588ce49e099e2bddfe3cdbe05, State: Running, Role: LEADER
I20260812 06:18:48.277963 28058 sys_catalog.cc:565] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:48.278016 28061 consensus_queue.cc:237] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [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: "adc3117588ce49e099e2bddfe3cdbe05" member_type: VOTER }
I20260812 06:18:48.278439 28062 sys_catalog.cc:455] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "adc3117588ce49e099e2bddfe3cdbe05" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adc3117588ce49e099e2bddfe3cdbe05" member_type: VOTER } }
I20260812 06:18:48.278457 28065 sys_catalog.cc:455] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [sys.catalog]: SysCatalogTable state changed. Reason: New leader adc3117588ce49e099e2bddfe3cdbe05. Latest consensus state: current_term: 1 leader_uuid: "adc3117588ce49e099e2bddfe3cdbe05" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adc3117588ce49e099e2bddfe3cdbe05" member_type: VOTER } }
I20260812 06:18:48.278581 28062 sys_catalog.cc:458] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:48.278656 28065 sys_catalog.cc:458] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:48.279256 28068 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:48.280226 28068 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:48.280464 27598 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:48.282143 28068 catalog_manager.cc:1383] Generated new cluster ID: 77fc7119f23b4927accc85e27b0d867d
I20260812 06:18:48.282208 28068 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:48.308569 28068 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:48.309140 28068 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:48.315830 28068 catalog_manager.cc:6092] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05: Generated new TSK 0
I20260812 06:18:48.316001 28068 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:48.345170 27598 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:48.347256 28090 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:48.347328 28093 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:48.347347 28087 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:48.347505 27598 server_base.cc:1061] running on GCE node
I20260812 06:18:48.347728 27598 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:48.347791 27598 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:48.347816 27598 hybrid_clock.cc:648] HybridClock initialized: now 1786515528347815 us; error 0 us; skew 500 ppm
I20260812 06:18:48.348726 27598 webserver.cc:533] Webserver started at http://127.26.243.129:43675/ using document root <none> and password file <none>
I20260812 06:18:48.348898 27598 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:48.348966 27598 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:48.349054 27598 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:48.349493 27598 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/instance:
uuid: "73731fba80794b11b4eb3e7ba1d7bea5"
format_stamp: "Formatted at 2026-08-12 06:18:48 on dist-test-slave-rwrg"
I20260812 06:18:48.350970 27598 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:48.351912 28102 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:48.352173 27598 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:48.352260 27598 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root
uuid: "73731fba80794b11b4eb3e7ba1d7bea5"
format_stamp: "Formatted at 2026-08-12 06:18:48 on dist-test-slave-rwrg"
I20260812 06:18:48.352350 27598 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:48.359169 27598 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:48.359519 27598 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:48.359793 27598 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:48.360219 27598 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:48.360278 27598 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:48.360337 27598 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:48.360383 27598 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:48.364894 27598 rpc_server.cc:307] RPC server started. Bound to: 127.26.243.129:35983
I20260812 06:18:48.364931 28222 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.243.129:35983 every 8 connection(s)
I20260812 06:18:48.370168 28223 heartbeater.cc:344] Connected to a master server at 127.26.243.190:34401
I20260812 06:18:48.370277 28223 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:48.370556 28223 heartbeater.cc:507] Master 127.26.243.190:34401 requested a full tablet report, sending...
I20260812 06:18:48.371243 27990 ts_manager.cc:194] Registered new tserver with Master: 73731fba80794b11b4eb3e7ba1d7bea5 (127.26.243.129:35983)
I20260812 06:18:48.371990 27990 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39430
I20260812 06:18:48.372073 27598 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006740109s
I20260812 06:18:48.379444 27990 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39442:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:48.388242 28160 tablet_service.cc:1511] Processing CreateTablet for tablet ee31ffe057074322867a59515ba53465 (DEFAULT_TABLE table=heavy-update-compaction-test [id=3025d25c09c54d9daa5c44d6062c4cf6]), partition=
I20260812 06:18:48.388614 28160 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ee31ffe057074322867a59515ba53465. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:48.390498 28237 tablet_bootstrap.cc:492] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Bootstrap starting.
I20260812 06:18:48.391281 28237 tablet_bootstrap.cc:654] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:48.392160 28237 tablet_bootstrap.cc:492] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: No bootstrap required, opened a new log
I20260812 06:18:48.392228 28237 ts_tablet_manager.cc:1403] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:48.392709 28237 raft_consensus.cc:359] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "73731fba80794b11b4eb3e7ba1d7bea5" member_type: VOTER last_known_addr { host: "127.26.243.129" port: 35983 } }
I20260812 06:18:48.392795 28237 raft_consensus.cc:385] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:48.392817 28237 raft_consensus.cc:740] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 73731fba80794b11b4eb3e7ba1d7bea5, State: Initialized, Role: FOLLOWER
I20260812 06:18:48.392948 28237 consensus_queue.cc:260] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5 [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: "73731fba80794b11b4eb3e7ba1d7bea5" member_type: VOTER last_known_addr { host: "127.26.243.129" port: 35983 } }
I20260812 06:18:48.393040 28237 raft_consensus.cc:399] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:48.393064 28237 raft_consensus.cc:493] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:48.393116 28237 raft_consensus.cc:3060] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:48.393822 28237 raft_consensus.cc:515] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "73731fba80794b11b4eb3e7ba1d7bea5" member_type: VOTER last_known_addr { host: "127.26.243.129" port: 35983 } }
I20260812 06:18:48.393988 28237 leader_election.cc:304] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5 [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: 73731fba80794b11b4eb3e7ba1d7bea5; no voters: 
I20260812 06:18:48.394136 28237 leader_election.cc:290] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:48.394265 28240 raft_consensus.cc:2804] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:48.394440 28237 ts_tablet_manager.cc:1434] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:48.394474 28240 raft_consensus.cc:697] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5 [term 1 LEADER]: Becoming Leader. State: Replica: 73731fba80794b11b4eb3e7ba1d7bea5, State: Running, Role: LEADER
I20260812 06:18:48.394515 28223 heartbeater.cc:499] Master 127.26.243.190:34401 was elected leader, sending a full tablet report...
I20260812 06:18:48.394637 28240 consensus_queue.cc:237] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5 [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: "73731fba80794b11b4eb3e7ba1d7bea5" member_type: VOTER last_known_addr { host: "127.26.243.129" port: 35983 } }
I20260812 06:18:48.395960 27990 catalog_manager.cc:5719] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5 reported cstate change: term changed from 0 to 1, leader changed from <none> to 73731fba80794b11b4eb3e7ba1d7bea5 (127.26.243.129). New cstate: current_term: 1 leader_uuid: "73731fba80794b11b4eb3e7ba1d7bea5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "73731fba80794b11b4eb3e7ba1d7bea5" member_type: VOTER last_known_addr { host: "127.26.243.129" port: 35983 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:48.452229 27598 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.018s	sys 0.004s
I20260812 06:18:48.615732 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushMRSOp(ee31ffe057074322867a59515ba53465): perf score=23.023690
I20260812 06:18:48.784873 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushMRSOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.169s	user 0.116s	sys 0.052s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":985,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43094,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:18:48.785758 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling LogGCOp(ee31ffe057074322867a59515ba53465): free 20743831 bytes of WAL
I20260812 06:18:48.786026 28112 log_reader.cc:385] T ee31ffe057074322867a59515ba53465: removed 2 log segments from log reader
I20260812 06:18:48.786090 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000001 (ops 1-6)
I20260812 06:18:48.786142 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000002 (ops 7-11)
I20260812 06:18:48.792586 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: LogGCOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.007s	user 0.000s	sys 0.007s Metrics: {}
I20260812 06:18:48.793076 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling UndoDeltaBlockGCOp(ee31ffe057074322867a59515ba53465): 20513813 bytes on disk
I20260812 06:18:48.793665 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: UndoDeltaBlockGCOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:18:48.794183 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=2.188937
I20260812 06:18:48.810271 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6128,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.810762 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:48.965713 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.155s	user 0.103s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":948,"lbm_read_time_us":10086,"lbm_reads_lt_1ms":460,"lbm_write_time_us":28030,"lbm_writes_lt_1ms":443,"mutex_wait_us":35,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4736,"thread_start_us":367,"threads_started":5,"update_count":2000}
I20260812 06:18:48.966259 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=11.118625
I20260812 06:18:49.008471 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.042s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17883,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:49.009045 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=2.188937
I20260812 06:18:49.024292 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.015s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4837,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:49.024981 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:49.179967 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.155s	user 0.083s	sys 0.065s 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":189,"lbm_read_time_us":10856,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25481,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:49.180685 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=14.095187
I20260812 06:18:49.226487 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.046s	user 0.031s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20529,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:49.226943 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=2.188937
I20260812 06:18:49.238205 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4276,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.238730 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:49.427372 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.188s	user 0.121s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":246,"lbm_read_time_us":11643,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29990,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:18:49.427906 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=14.095187
I20260812 06:18:49.475982 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.048s	user 0.030s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19895,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:49.476435 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=2.188937
I20260812 06:18:49.488003 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4347,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.488636 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:49.645550 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.157s	user 0.115s	sys 0.036s 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":470,"lbm_read_time_us":11931,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30287,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:18:49.646199 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=11.118625
I20260812 06:18:49.707945 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.062s	user 0.016s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":33749,"lbm_writes_1-10_ms":2,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1550}
I20260812 06:18:49.708613 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=6.157687
I20260812 06:18:49.733968 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.025s	user 0.013s	sys 0.009s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":9928,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:49.734519 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:49.901017 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.166s	user 0.115s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":295,"lbm_read_time_us":9717,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":563,"lbm_write_time_us":36927,"lbm_writes_lt_1ms":543,"mutex_wait_us":101,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:18:49.901520 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=14.095187
I20260812 06:18:49.955209 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.054s	user 0.029s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20078,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:49.955750 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=2.188937
I20260812 06:18:49.966229 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4006,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.966814 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushMRSOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:49.995914 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushMRSOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":41,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1507,"drs_written":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1795,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:49.996466 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling LogGCOp(ee31ffe057074322867a59515ba53465): free 120553370 bytes of WAL
I20260812 06:18:49.996739 28112 log_reader.cc:385] T ee31ffe057074322867a59515ba53465: removed 12 log segments from log reader
I20260812 06:18:49.996798 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000003 (ops 12-16)
I20260812 06:18:49.996850 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000004 (ops 17-20)
I20260812 06:18:49.996955 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000005 (ops 21-25)
I20260812 06:18:49.996999 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000006 (ops 26-30)
I20260812 06:18:49.997023 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000007 (ops 31-35)
I20260812 06:18:49.997061 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000008 (ops 36-40)
I20260812 06:18:49.997099 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000009 (ops 41-45)
I20260812 06:18:49.997135 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000010 (ops 46-50)
I20260812 06:18:49.997171 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000011 (ops 51-54)
I20260812 06:18:49.997210 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000012 (ops 55-59)
I20260812 06:18:49.997247 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000013 (ops 60-64)
I20260812 06:18:49.997284 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000014 (ops 65-69)
I20260812 06:18:50.021819 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: LogGCOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:18:50.022203 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=3.181125
I20260812 06:18:50.041810 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.019s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7126,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:50.042272 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling UndoDeltaBlockGCOp(ee31ffe057074322867a59515ba53465): 447 bytes on disk
I20260812 06:18:50.042646 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: UndoDeltaBlockGCOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:18:50.043076 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=2.188937
I20260812 06:18:50.052783 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3701,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:50.053180 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:50.302383 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.249s	user 0.150s	sys 0.085s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020736,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":895,"lbm_read_time_us":14736,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41736,"lbm_writes_lt_1ms":743,"mutex_wait_us":52,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17408,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:18:50.302848 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=18.063937
I20260812 06:18:50.372653 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.070s	user 0.030s	sys 0.039s Metrics: {"bytes_written":20512323,"delete_count":0,"lbm_write_time_us":29306,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:18:50.373386 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=2.188937
I20260812 06:18:50.389178 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6406,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:50.389621 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:50.620875 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.231s	user 0.146s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918105,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1076,"lbm_read_time_us":14322,"lbm_reads_lt_1ms":668,"lbm_write_time_us":38583,"lbm_writes_lt_1ms":643,"mutex_wait_us":296,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":3000}
I20260812 06:18:50.621546 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=18.063937
I20260812 06:18:50.674043 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.052s	user 0.028s	sys 0.021s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":22962,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:50.674685 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:50.849486 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.175s	user 0.124s	sys 0.045s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24815566,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":124,"lbm_read_time_us":12140,"lbm_reads_lt_1ms":563,"lbm_write_time_us":28316,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:18:50.850597 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=15.087375
I20260812 06:18:50.912344 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.062s	user 0.017s	sys 0.032s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":19972,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:50.912860 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=6.157687
I20260812 06:18:50.933648 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.021s	user 0.006s	sys 0.013s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8721,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:50.934240 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:51.134145 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.200s	user 0.128s	sys 0.071s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":592,"lbm_read_time_us":13590,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36634,"lbm_writes_lt_1ms":643,"mutex_wait_us":69,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":3000}
I20260812 06:18:51.135087 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=14.095187
I20260812 06:18:51.175333 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.040s	user 0.022s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17404,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:51.175871 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=2.188937
I20260812 06:18:51.202900 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.027s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5467,"lbm_writes_lt_1ms":103,"mutex_wait_us":2,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.203389 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=2.188937
I20260812 06:18:51.217669 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5530,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.218235 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:51.425927 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.207s	user 0.118s	sys 0.082s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918213,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1144,"lbm_read_time_us":12846,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33660,"lbm_writes_lt_1ms":643,"mutex_wait_us":74,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":3000}
I20260812 06:18:51.426739 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=17.071750
I20260812 06:18:51.493750 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.067s	user 0.038s	sys 0.015s Metrics: {"bytes_written":18871349,"delete_count":0,"lbm_write_time_us":24524,"lbm_writes_lt_1ms":463,"reinsert_count":0,"update_count":2300}
I20260812 06:18:51.494215 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=4.173312
I20260812 06:18:51.512643 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.018s	user 0.006s	sys 0.012s Metrics: {"bytes_written":5743636,"delete_count":0,"lbm_write_time_us":7085,"lbm_writes_lt_1ms":143,"reinsert_count":0,"update_count":700}
I20260812 06:18:51.513306 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushMRSOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:51.547945 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushMRSOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.034s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":179,"dirs.run_wall_time_us":1295,"drs_written":1,"lbm_read_time_us":116,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2063,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:51.548830 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling LogGCOp(ee31ffe057074322867a59515ba53465): free 124257299 bytes of WAL
I20260812 06:18:51.549149 28112 log_reader.cc:385] T ee31ffe057074322867a59515ba53465: removed 12 log segments from log reader
I20260812 06:18:51.549256 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000015 (ops 70-74)
I20260812 06:18:51.549309 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000016 (ops 75-79)
I20260812 06:18:51.549428 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000017 (ops 80-84)
I20260812 06:18:51.549475 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000018 (ops 85-89)
I20260812 06:18:51.549511 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000019 (ops 90-94)
I20260812 06:18:51.549535 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000020 (ops 95-99)
I20260812 06:18:51.549614 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000021 (ops 100-104)
I20260812 06:18:51.549706 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000022 (ops 105-109)
I20260812 06:18:51.549768 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000023 (ops 110-114)
I20260812 06:18:51.549820 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000024 (ops 115-118)
I20260812 06:18:51.549889 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000025 (ops 119-123)
I20260812 06:18:51.549930 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000026 (ops 124-128)
I20260812 06:18:51.574795 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: LogGCOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:51.575345 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=6.157687
I20260812 06:18:51.599440 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.024s	user 0.018s	sys 0.004s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":9571,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:51.599987 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling LogGCOp(ee31ffe057074322867a59515ba53465): free 8767146 bytes of WAL
I20260812 06:18:51.600292 28112 log_reader.cc:385] T ee31ffe057074322867a59515ba53465: removed 1 log segments from log reader
I20260812 06:18:51.600370 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000027 (ops 129-133)
I20260812 06:18:51.602124 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: LogGCOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:51.602579 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:51.841580 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.239s	user 0.141s	sys 0.087s Metrics: {"cfile_cache_miss":833,"cfile_cache_miss_bytes":37123047,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":163,"lbm_read_time_us":15393,"lbm_reads_lt_1ms":865,"lbm_write_time_us":42934,"lbm_writes_lt_1ms":843,"mutex_wait_us":21,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":10368,"thread_start_us":72,"threads_started":1,"update_count":4000}
I20260812 06:18:51.842658 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling UndoDeltaBlockGCOp(ee31ffe057074322867a59515ba53465): 493 bytes on disk
I20260812 06:18:51.843684 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: UndoDeltaBlockGCOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":90,"lbm_reads_lt_1ms":4}
I20260812 06:18:51.844578 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=22.032687
I20260812 06:18:51.913408 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.069s	user 0.047s	sys 0.021s Metrics: {"bytes_written":24614734,"delete_count":0,"lbm_write_time_us":30433,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:18:51.913961 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=2.188937
I20260812 06:18:51.937707 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.024s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5425,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.938153 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=2.188937
I20260812 06:18:51.948271 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4094,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.948726 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:52.139850 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.191s	user 0.149s	sys 0.041s Metrics: {"cfile_cache_miss":833,"cfile_cache_miss_bytes":37123047,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":264,"lbm_read_time_us":14160,"lbm_reads_lt_1ms":873,"lbm_write_time_us":41189,"lbm_writes_lt_1ms":843,"mutex_wait_us":21,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":4000}
I20260812 06:18:52.140442 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=18.063937
I20260812 06:18:52.191958 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.051s	user 0.025s	sys 0.021s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":21840,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:52.192611 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=2.188937
I20260812 06:18:52.206038 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5101,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.206521 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:52.373642 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.167s	user 0.131s	sys 0.036s 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":499,"lbm_read_time_us":11544,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34763,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":3000}
I20260812 06:18:52.374294 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=14.095187
I20260812 06:18:52.426151 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.052s	user 0.030s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18776,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:52.426694 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=2.188937
I20260812 06:18:52.441608 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5380,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.442121 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:52.622663 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.180s	user 0.113s	sys 0.055s 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":308,"lbm_read_time_us":11532,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31285,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:18:52.623267 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=14.095187
I20260812 06:18:52.687458 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.064s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24435,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:52.687922 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=2.188937
I20260812 06:18:52.698482 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4009,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.699267 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:52.874202 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.175s	user 0.120s	sys 0.053s 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":176,"lbm_read_time_us":12163,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29245,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:18:52.874926 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=14.095187
I20260812 06:18:52.928254 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.053s	user 0.023s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18483,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:52.928805 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=2.188937
I20260812 06:18:52.940167 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4243,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.940769 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushMRSOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:52.972685 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushMRSOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.032s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1239,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1625,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:52.973312 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling LogGCOp(ee31ffe057074322867a59515ba53465): free 124257506 bytes of WAL
I20260812 06:18:52.973621 28112 log_reader.cc:385] T ee31ffe057074322867a59515ba53465: removed 12 log segments from log reader
I20260812 06:18:52.973687 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000028 (ops 134-138)
I20260812 06:18:52.973739 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000029 (ops 139-143)
I20260812 06:18:52.973788 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000030 (ops 144-148)
I20260812 06:18:52.973825 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000031 (ops 149-153)
I20260812 06:18:52.973868 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000032 (ops 154-158)
I20260812 06:18:52.973902 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000033 (ops 159-163)
I20260812 06:18:52.973940 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000034 (ops 164-168)
I20260812 06:18:52.973979 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000035 (ops 169-173)
I20260812 06:18:52.974025 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000036 (ops 174-178)
I20260812 06:18:52.974063 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000037 (ops 179-183)
I20260812 06:18:52.974102 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000038 (ops 184-188)
I20260812 06:18:52.974139 28112 log.cc:1079] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: Deleting log segment in path: /tmp/dist-test-taskx5YWpz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515522803232-27598-0/minicluster-data/ts-0-root/wals/ee31ffe057074322867a59515ba53465/wal-000000039 (ops 189-192)
I20260812 06:18:53.001953 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: LogGCOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:53.002709 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling UndoDeltaBlockGCOp(ee31ffe057074322867a59515ba53465): 472 bytes on disk
I20260812 06:18:53.003228 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: UndoDeltaBlockGCOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:18:53.003834 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=5.165500
I20260812 06:18:53.023898 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.020s	user 0.010s	sys 0.007s Metrics: {"bytes_written":6851279,"delete_count":0,"lbm_write_time_us":8445,"lbm_writes_lt_1ms":170,"reinsert_count":0,"update_count":835}
I20260812 06:18:53.024381 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:53.033165 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.009s	user 0.006s	sys 0.001s Metrics: {"bytes_written":1353977,"delete_count":0,"lbm_write_time_us":2519,"lbm_writes_lt_1ms":36,"reinsert_count":0,"update_count":165}
I20260812 06:18:53.033643 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465): perf score=1.000000
I20260812 06:18:53.144942 27598 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.693s	user 1.820s	sys 0.130s
I20260812 06:18:53.227285 27598 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.082s	user 0.001s	sys 0.000s
I20260812 06:18:53.227759 27598 tablet_server.cc:179] TabletServer@127.26.243.129:0 shutting down...
I20260812 06:18:53.242278 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: MajorDeltaCompactionOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.208s	user 0.116s	sys 0.091s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020678,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":479,"lbm_read_time_us":14762,"lbm_reads_lt_1ms":770,"lbm_write_time_us":34628,"lbm_writes_lt_1ms":743,"mutex_wait_us":16,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":21504,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:18:53.244033 28224 maintenance_manager.cc:419] P 73731fba80794b11b4eb3e7ba1d7bea5: Scheduling FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465): perf score=10.126437
I20260812 06:18:53.272928 28112 maintenance_manager.cc:643] P 73731fba80794b11b4eb3e7ba1d7bea5: FlushDeltaMemStoresOp(ee31ffe057074322867a59515ba53465) complete. Timing: real 0.029s	user 0.025s	sys 0.003s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13151,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:53.273701 27598 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:53.274013 27598 tablet_replica.cc:333] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5: stopping tablet replica
I20260812 06:18:53.274173 27598 raft_consensus.cc:2243] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:53.274322 27598 raft_consensus.cc:2272] T ee31ffe057074322867a59515ba53465 P 73731fba80794b11b4eb3e7ba1d7bea5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:53.287966 27598 tablet_server.cc:196] TabletServer@127.26.243.129:0 shutdown complete.
I20260812 06:18:53.296840 27598 master.cc:562] Master@127.26.243.190:34401 shutting down...
I20260812 06:18:53.300159 27598 raft_consensus.cc:2243] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:53.300311 27598 raft_consensus.cc:2272] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:53.300360 27598 tablet_replica.cc:333] T 00000000000000000000000000000000 P adc3117588ce49e099e2bddfe3cdbe05: stopping tablet replica
I20260812 06:18:53.312690 27598 master.cc:584] Master@127.26.243.190:34401 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5174 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10585 ms total)

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