[==========] 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:01.001253 25567 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.247.254:40303
I20260812 06:18:01.002218 25567 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:01.002763 25567 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:01.009115 25576 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:01.009176 25574 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:01.009277 25567 server_base.cc:1061] running on GCE node
W20260812 06:18:01.009428 25573 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:01.009872 25567 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:01.009963 25567 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:01.010028 25567 hybrid_clock.cc:648] HybridClock initialized: now 1786515481010026 us; error 0 us; skew 500 ppm
I20260812 06:18:01.011876 25567 webserver.cc:533] Webserver started at http://127.24.247.254:46423/ using document root <none> and password file <none>
I20260812 06:18:01.012377 25567 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:01.012432 25567 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:01.012622 25567 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:01.014211 25567 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/master-0-root/instance:
uuid: "54b3b75cf4154a27a10522ca7e0f93ef"
format_stamp: "Formatted at 2026-08-12 06:18:01 on dist-test-slave-07c2"
I20260812 06:18:01.017637 25567 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:18:01.019666 25581 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:01.020697 25567 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:01.020839 25567 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/master-0-root
uuid: "54b3b75cf4154a27a10522ca7e0f93ef"
format_stamp: "Formatted at 2026-08-12 06:18:01 on dist-test-slave-07c2"
I20260812 06:18:01.020949 25567 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-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:01.049109 25567 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:01.049820 25567 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:01.050022 25567 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:01.057907 25567 rpc_server.cc:307] RPC server started. Bound to: 127.24.247.254:40303
I20260812 06:18:01.057930 25653 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.247.254:40303 every 8 connection(s)
I20260812 06:18:01.060220 25654 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:01.065739 25654 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef: Bootstrap starting.
I20260812 06:18:01.068142 25654 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:01.069092 25654 log.cc:826] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:01.070792 25654 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef: No bootstrap required, opened a new log
I20260812 06:18:01.073652 25654 raft_consensus.cc:359] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54b3b75cf4154a27a10522ca7e0f93ef" member_type: VOTER }
I20260812 06:18:01.073832 25654 raft_consensus.cc:385] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:01.073874 25654 raft_consensus.cc:740] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 54b3b75cf4154a27a10522ca7e0f93ef, State: Initialized, Role: FOLLOWER
I20260812 06:18:01.074491 25654 consensus_queue.cc:260] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [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: "54b3b75cf4154a27a10522ca7e0f93ef" member_type: VOTER }
I20260812 06:18:01.074635 25654 raft_consensus.cc:399] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:01.074685 25654 raft_consensus.cc:493] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:01.074785 25654 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:01.075570 25654 raft_consensus.cc:515] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54b3b75cf4154a27a10522ca7e0f93ef" member_type: VOTER }
I20260812 06:18:01.075977 25654 leader_election.cc:304] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [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: 54b3b75cf4154a27a10522ca7e0f93ef; no voters: 
I20260812 06:18:01.076254 25654 leader_election.cc:290] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:01.076432 25659 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:01.076714 25659 raft_consensus.cc:697] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [term 1 LEADER]: Becoming Leader. State: Replica: 54b3b75cf4154a27a10522ca7e0f93ef, State: Running, Role: LEADER
I20260812 06:18:01.077116 25659 consensus_queue.cc:237] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [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: "54b3b75cf4154a27a10522ca7e0f93ef" member_type: VOTER }
I20260812 06:18:01.077329 25654 sys_catalog.cc:565] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:01.079011 25660 sys_catalog.cc:455] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "54b3b75cf4154a27a10522ca7e0f93ef" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54b3b75cf4154a27a10522ca7e0f93ef" member_type: VOTER } }
I20260812 06:18:01.079038 25661 sys_catalog.cc:455] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [sys.catalog]: SysCatalogTable state changed. Reason: New leader 54b3b75cf4154a27a10522ca7e0f93ef. Latest consensus state: current_term: 1 leader_uuid: "54b3b75cf4154a27a10522ca7e0f93ef" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54b3b75cf4154a27a10522ca7e0f93ef" member_type: VOTER } }
I20260812 06:18:01.079133 25660 sys_catalog.cc:458] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:01.079142 25661 sys_catalog.cc:458] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:01.079627 25674 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:01.079926 25567 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:01.081892 25674 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:01.086319 25674 catalog_manager.cc:1383] Generated new cluster ID: 547b095d046f482e90f1ae594eb216a7
I20260812 06:18:01.086390 25674 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:01.094460 25674 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:01.095489 25674 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:01.105736 25674 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef: Generated new TSK 0
I20260812 06:18:01.106487 25674 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:01.112336 25567 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:01.114960 25689 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:01.114939 25686 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:01.114929 25685 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:01.115224 25567 server_base.cc:1061] running on GCE node
I20260812 06:18:01.115437 25567 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:01.115483 25567 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:01.115499 25567 hybrid_clock.cc:648] HybridClock initialized: now 1786515481115499 us; error 0 us; skew 500 ppm
I20260812 06:18:01.116353 25567 webserver.cc:533] Webserver started at http://127.24.247.193:37453/ using document root <none> and password file <none>
I20260812 06:18:01.116532 25567 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:01.116585 25567 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:01.116679 25567 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:01.117092 25567 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/instance:
uuid: "bfa6093e298642ca8d7bead1fa4a3f78"
format_stamp: "Formatted at 2026-08-12 06:18:01 on dist-test-slave-07c2"
I20260812 06:18:01.118577 25567 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:01.119571 25695 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:01.119827 25567 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:01.119897 25567 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root
uuid: "bfa6093e298642ca8d7bead1fa4a3f78"
format_stamp: "Formatted at 2026-08-12 06:18:01 on dist-test-slave-07c2"
I20260812 06:18:01.119989 25567 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-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:01.128352 25567 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:01.128775 25567 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:01.129253 25567 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:01.130137 25567 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:01.130189 25567 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:01.130260 25567 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:01.130298 25567 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:01.137315 25567 rpc_server.cc:307] RPC server started. Bound to: 127.24.247.193:43633
I20260812 06:18:01.137343 25767 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.247.193:43633 every 8 connection(s)
I20260812 06:18:01.147262 25768 heartbeater.cc:344] Connected to a master server at 127.24.247.254:40303
I20260812 06:18:01.147567 25768 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:01.148056 25768 heartbeater.cc:507] Master 127.24.247.254:40303 requested a full tablet report, sending...
I20260812 06:18:01.149576 25607 ts_manager.cc:194] Registered new tserver with Master: bfa6093e298642ca8d7bead1fa4a3f78 (127.24.247.193:43633)
I20260812 06:18:01.150310 25567 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01231733s
I20260812 06:18:01.151129 25607 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47358
I20260812 06:18:01.160511 25607 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47372:
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:01.176458 25727 tablet_service.cc:1511] Processing CreateTablet for tablet a93ad22d63f549fab97ccd5aea32c21e (DEFAULT_TABLE table=heavy-update-compaction-test [id=1fd6c8f490ff45f3ba00321378075046]), partition=
I20260812 06:18:01.176930 25727 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a93ad22d63f549fab97ccd5aea32c21e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:01.179353 25785 tablet_bootstrap.cc:492] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Bootstrap starting.
I20260812 06:18:01.180280 25785 tablet_bootstrap.cc:654] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:01.181466 25785 tablet_bootstrap.cc:492] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: No bootstrap required, opened a new log
I20260812 06:18:01.181603 25785 ts_tablet_manager.cc:1403] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:01.182155 25785 raft_consensus.cc:359] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfa6093e298642ca8d7bead1fa4a3f78" member_type: VOTER last_known_addr { host: "127.24.247.193" port: 43633 } }
I20260812 06:18:01.182263 25785 raft_consensus.cc:385] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:01.182288 25785 raft_consensus.cc:740] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bfa6093e298642ca8d7bead1fa4a3f78, State: Initialized, Role: FOLLOWER
I20260812 06:18:01.182495 25785 consensus_queue.cc:260] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78 [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: "bfa6093e298642ca8d7bead1fa4a3f78" member_type: VOTER last_known_addr { host: "127.24.247.193" port: 43633 } }
I20260812 06:18:01.182585 25785 raft_consensus.cc:399] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:01.182634 25785 raft_consensus.cc:493] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:01.182693 25785 raft_consensus.cc:3060] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:01.183496 25785 raft_consensus.cc:515] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfa6093e298642ca8d7bead1fa4a3f78" member_type: VOTER last_known_addr { host: "127.24.247.193" port: 43633 } }
I20260812 06:18:01.183646 25785 leader_election.cc:304] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78 [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: bfa6093e298642ca8d7bead1fa4a3f78; no voters: 
I20260812 06:18:01.183887 25785 leader_election.cc:290] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:01.183980 25787 raft_consensus.cc:2804] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:01.184165 25787 raft_consensus.cc:697] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78 [term 1 LEADER]: Becoming Leader. State: Replica: bfa6093e298642ca8d7bead1fa4a3f78, State: Running, Role: LEADER
I20260812 06:18:01.184262 25785 ts_tablet_manager.cc:1434] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:01.184371 25787 consensus_queue.cc:237] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78 [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: "bfa6093e298642ca8d7bead1fa4a3f78" member_type: VOTER last_known_addr { host: "127.24.247.193" port: 43633 } }
I20260812 06:18:01.184569 25768 heartbeater.cc:499] Master 127.24.247.254:40303 was elected leader, sending a full tablet report...
I20260812 06:18:01.187153 25607 catalog_manager.cc:5719] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78 reported cstate change: term changed from 0 to 1, leader changed from <none> to bfa6093e298642ca8d7bead1fa4a3f78 (127.24.247.193). New cstate: current_term: 1 leader_uuid: "bfa6093e298642ca8d7bead1fa4a3f78" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfa6093e298642ca8d7bead1fa4a3f78" member_type: VOTER last_known_addr { host: "127.24.247.193" port: 43633 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:01.266849 25567 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.073s	user 0.019s	sys 0.013s
I20260812 06:18:01.388437 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushMRSOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=15.086190
I20260812 06:18:01.557312 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushMRSOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.169s	user 0.101s	sys 0.056s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":201,"delete_count":0,"dirs.queue_time_us":198,"dirs.run_cpu_time_us":177,"dirs.run_wall_time_us":1992,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41890,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":88,"threads_started":1,"update_count":1450}
I20260812 06:18:01.558311 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling LogGCOp(a93ad22d63f549fab97ccd5aea32c21e): free 20743880 bytes of WAL
I20260812 06:18:01.558629 25703 log_reader.cc:385] T a93ad22d63f549fab97ccd5aea32c21e: removed 2 log segments from log reader
I20260812 06:18:01.558706 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000001 (ops 1-6)
I20260812 06:18:01.558775 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000002 (ops 7-11)
I20260812 06:18:01.563087 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: LogGCOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:01.563467 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling UndoDeltaBlockGCOp(a93ad22d63f549fab97ccd5aea32c21e): 12719214 bytes on disk
I20260812 06:18:01.564016 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: UndoDeltaBlockGCOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:18:01.564416 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:01.582046 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6690,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.582558 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:01.715992 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.133s	user 0.113s	sys 0.020s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1246,"lbm_read_time_us":10337,"lbm_reads_lt_1ms":454,"lbm_write_time_us":22532,"lbm_writes_lt_1ms":433,"mutex_wait_us":64,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":383,"threads_started":5,"update_count":1950}
I20260812 06:18:01.716634 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=10.126437
I20260812 06:18:01.755554 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.039s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15600,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:01.756057 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:01.770860 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5657,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.771467 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:01.901868 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.130s	user 0.081s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1109,"lbm_read_time_us":9724,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24698,"lbm_writes_lt_1ms":443,"mutex_wait_us":323,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":26752,"update_count":2000}
I20260812 06:18:01.902493 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=10.126437
I20260812 06:18:01.935825 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.033s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14693,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:01.936344 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:02.046522 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.110s	user 0.092s	sys 0.017s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":197,"lbm_read_time_us":6233,"lbm_reads_lt_1ms":367,"lbm_write_time_us":18676,"lbm_writes_lt_1ms":343,"mutex_wait_us":70,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:18:02.047147 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=10.126437
I20260812 06:18:02.092581 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.045s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15480,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:02.093101 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:02.106001 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4868,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.106686 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:02.242295 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.135s	user 0.106s	sys 0.029s 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":996,"lbm_read_time_us":7872,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27762,"lbm_writes_lt_1ms":443,"mutex_wait_us":286,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:18:02.242779 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=10.126437
I20260812 06:18:02.288653 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.046s	user 0.016s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16071,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:02.289135 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:02.299985 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3914,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.300587 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:02.432565 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.132s	user 0.096s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":195,"lbm_read_time_us":10610,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23879,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2000}
I20260812 06:18:02.433169 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=10.126437
I20260812 06:18:02.477699 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.044s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15869,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:02.478266 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:02.490142 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4047,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.490823 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:02.618000 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.127s	user 0.104s	sys 0.020s 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":963,"lbm_read_time_us":8249,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24640,"lbm_writes_lt_1ms":443,"mutex_wait_us":302,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2000}
I20260812 06:18:02.618777 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=10.126437
I20260812 06:18:02.662588 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.043s	user 0.010s	sys 0.026s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14266,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:02.663193 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:02.673924 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4160,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.674404 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:02.823834 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.149s	user 0.105s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":227,"lbm_read_time_us":11046,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25173,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:18:02.824527 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=10.126437
I20260812 06:18:02.865772 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.041s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18315,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:02.866297 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:02.878019 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4531,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.878536 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushMRSOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:02.907759 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushMRSOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.029s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":258,"dirs.run_wall_time_us":1517,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1474,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:02.908569 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling LogGCOp(a93ad22d63f549fab97ccd5aea32c21e): free 121006435 bytes of WAL
I20260812 06:18:02.908816 25703 log_reader.cc:385] T a93ad22d63f549fab97ccd5aea32c21e: removed 12 log segments from log reader
I20260812 06:18:02.908861 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000003 (ops 12-16)
I20260812 06:18:02.908890 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000004 (ops 17-20)
I20260812 06:18:02.908951 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000005 (ops 21-25)
I20260812 06:18:02.908994 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000006 (ops 26-30)
I20260812 06:18:02.909032 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000007 (ops 31-35)
I20260812 06:18:02.909096 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000008 (ops 36-40)
I20260812 06:18:02.909133 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000009 (ops 41-45)
I20260812 06:18:02.909171 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000010 (ops 46-50)
I20260812 06:18:02.909210 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000011 (ops 51-55)
I20260812 06:18:02.909251 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000012 (ops 56-60)
I20260812 06:18:02.909288 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000013 (ops 61-65)
I20260812 06:18:02.909327 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000014 (ops 66-70)
I20260812 06:18:02.937727 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: LogGCOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:02.938309 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling UndoDeltaBlockGCOp(a93ad22d63f549fab97ccd5aea32c21e): 472 bytes on disk
I20260812 06:18:02.938979 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: UndoDeltaBlockGCOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:18:02.939620 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=4.173312
I20260812 06:18:02.964366 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.025s	user 0.009s	sys 0.014s Metrics: {"bytes_written":5497489,"delete_count":0,"lbm_write_time_us":6482,"lbm_writes_lt_1ms":137,"reinsert_count":0,"update_count":670}
I20260812 06:18:02.964989 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.196750
I20260812 06:18:02.972759 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.008s	user 0.005s	sys 0.001s Metrics: {"bytes_written":2707805,"delete_count":0,"lbm_write_time_us":2660,"lbm_writes_lt_1ms":69,"reinsert_count":0,"update_count":330}
I20260812 06:18:02.973197 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:03.170781 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.197s	user 0.146s	sys 0.049s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877309,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":157,"lbm_read_time_us":14827,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35150,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4608,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:18:03.171343 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=11.118625
I20260812 06:18:03.205817 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.034s	user 0.027s	sys 0.005s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":14718,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:03.206493 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:03.235965 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.029s	user 0.013s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5822,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:03.236595 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:03.246486 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.010s	user 0.001s	sys 0.005s Metrics: {"bytes_written":1436031,"delete_count":0,"lbm_write_time_us":2285,"lbm_writes_lt_1ms":38,"reinsert_count":0,"update_count":175}
I20260812 06:18:03.246922 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.196750
I20260812 06:18:03.254384 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.007s	user 0.003s	sys 0.003s Metrics: {"bytes_written":2666779,"delete_count":0,"lbm_write_time_us":2709,"lbm_writes_lt_1ms":68,"reinsert_count":0,"update_count":325}
I20260812 06:18:03.254799 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:03.427911 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.173s	user 0.126s	sys 0.044s Metrics: {"cfile_cache_miss":534,"cfile_cache_miss_bytes":24774825,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":146,"lbm_read_time_us":10937,"lbm_reads_lt_1ms":574,"lbm_write_time_us":29253,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:03.428577 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=11.118625
I20260812 06:18:03.466114 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.037s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16147,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:03.466691 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:03.481256 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4927,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:03.481769 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:03.640589 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.159s	user 0.127s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":231,"lbm_read_time_us":8867,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27345,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2000}
I20260812 06:18:03.641294 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=10.126437
I20260812 06:18:03.674355 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.033s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14012,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:03.674947 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:03.691162 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6320,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.691746 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:03.826382 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.134s	user 0.102s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":295,"lbm_read_time_us":7463,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26208,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":85760,"update_count":2000}
I20260812 06:18:03.827235 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=10.126437
I20260812 06:18:03.873143 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.046s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17086,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:03.873648 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:03.888729 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.015s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5625,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.889410 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:04.019316 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.130s	user 0.109s	sys 0.020s 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":694,"lbm_read_time_us":8429,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25516,"lbm_writes_lt_1ms":443,"mutex_wait_us":79,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:18:04.019841 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=10.126437
I20260812 06:18:04.073704 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.054s	user 0.037s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16452,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:04.074273 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:04.090842 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6187,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.091437 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:04.254295 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.163s	user 0.128s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":670,"lbm_read_time_us":11657,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24991,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2000}
I20260812 06:18:04.255193 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=10.126437
I20260812 06:18:04.300380 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.045s	user 0.010s	sys 0.032s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19247,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:04.300918 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:04.317349 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.016s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4637,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.317922 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushMRSOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:04.367671 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushMRSOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.050s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1403,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2165,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:04.368609 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling LogGCOp(a93ad22d63f549fab97ccd5aea32c21e): free 115490139 bytes of WAL
I20260812 06:18:04.368860 25703 log_reader.cc:385] T a93ad22d63f549fab97ccd5aea32c21e: removed 11 log segments from log reader
I20260812 06:18:04.368930 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000015 (ops 71-75)
I20260812 06:18:04.368983 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000016 (ops 76-80)
I20260812 06:18:04.369041 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000017 (ops 81-84)
I20260812 06:18:04.369086 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000018 (ops 85-89)
I20260812 06:18:04.369125 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000019 (ops 90-94)
I20260812 06:18:04.369164 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000020 (ops 95-99)
I20260812 06:18:04.369202 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000021 (ops 100-104)
I20260812 06:18:04.369246 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000022 (ops 105-109)
I20260812 06:18:04.369283 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000023 (ops 110-114)
I20260812 06:18:04.369323 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000024 (ops 115-119)
I20260812 06:18:04.369364 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000025 (ops 120-124)
I20260812 06:18:04.394027 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: LogGCOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:04.394600 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=6.157687
I20260812 06:18:04.417423 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.023s	user 0.012s	sys 0.008s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":9208,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:04.417946 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:04.428568 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4194,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.429160 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling UndoDeltaBlockGCOp(a93ad22d63f549fab97ccd5aea32c21e): 448 bytes on disk
I20260812 06:18:04.429683 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: UndoDeltaBlockGCOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:18:04.430256 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:04.641362 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.211s	user 0.143s	sys 0.067s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":551,"lbm_read_time_us":15180,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36284,"lbm_writes_lt_1ms":743,"mutex_wait_us":34,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13184,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:18:04.642236 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=14.095187
I20260812 06:18:04.695488 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.053s	user 0.042s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23433,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:04.696024 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:04.711632 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5966,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.712167 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:04.895937 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.184s	user 0.125s	sys 0.053s 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":236,"lbm_read_time_us":13222,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31848,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":38528,"update_count":2500}
I20260812 06:18:04.896519 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=14.095187
I20260812 06:18:04.956194 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.059s	user 0.016s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20125,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:04.956702 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:04.967276 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4198,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.967783 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:05.164613 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.197s	user 0.132s	sys 0.060s 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":287,"lbm_read_time_us":13390,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35712,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:18:05.165403 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=11.118625
I20260812 06:18:05.209075 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.043s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15246,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:05.209724 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:05.225276 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.015s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4433,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.225781 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:05.235641 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3856,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:05.236088 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:05.410458 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.174s	user 0.138s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":195,"lbm_read_time_us":12231,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29814,"lbm_writes_lt_1ms":543,"mutex_wait_us":80,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:18:05.411253 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=11.118625
I20260812 06:18:05.450093 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.039s	user 0.029s	sys 0.005s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15795,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:05.450882 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:05.477455 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.026s	user 0.009s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4764,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.478021 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:05.488442 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4005,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:05.488898 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:05.662961 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.174s	user 0.109s	sys 0.064s 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":1343,"lbm_read_time_us":12013,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30258,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:05.663563 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=10.126437
I20260812 06:18:05.701967 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.038s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12430564,"delete_count":0,"lbm_write_time_us":16932,"lbm_writes_lt_1ms":306,"reinsert_count":0,"update_count":1515}
I20260812 06:18:05.702513 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:05.713727 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":4093,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:18:05.714183 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:05.841647 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.127s	user 0.110s	sys 0.017s 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":325,"lbm_read_time_us":9492,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22808,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":43904,"update_count":2000}
I20260812 06:18:05.842396 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=10.126437
I20260812 06:18:05.880720 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.038s	user 0.033s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16027,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:05.881222 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:05.893148 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4286,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.893748 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushMRSOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:05.926164 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushMRSOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":185,"dirs.run_wall_time_us":1452,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1870,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:05.926877 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling LogGCOp(a93ad22d63f549fab97ccd5aea32c21e): free 124710552 bytes of WAL
I20260812 06:18:05.927141 25703 log_reader.cc:385] T a93ad22d63f549fab97ccd5aea32c21e: removed 12 log segments from log reader
I20260812 06:18:05.927187 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000026 (ops 125-129)
I20260812 06:18:05.927215 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000027 (ops 130-134)
I20260812 06:18:05.927261 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000028 (ops 135-139)
I20260812 06:18:05.927318 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000029 (ops 140-144)
I20260812 06:18:05.927359 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000030 (ops 145-149)
I20260812 06:18:05.927402 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000031 (ops 150-154)
I20260812 06:18:05.927423 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000032 (ops 155-159)
I20260812 06:18:05.927480 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000033 (ops 160-164)
I20260812 06:18:05.927521 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000034 (ops 165-169)
I20260812 06:18:05.927562 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000035 (ops 170-174)
I20260812 06:18:05.927601 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000036 (ops 175-179)
I20260812 06:18:05.927644 25703 log.cc:1079] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/a93ad22d63f549fab97ccd5aea32c21e/wal-000000037 (ops 180-184)
I20260812 06:18:05.954849 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: LogGCOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.028s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:18:05.955240 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling UndoDeltaBlockGCOp(a93ad22d63f549fab97ccd5aea32c21e): 472 bytes on disk
I20260812 06:18:05.955821 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: UndoDeltaBlockGCOp(a93ad22d63f549fab97ccd5aea32c21e) 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:05.956636 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=5.165500
I20260812 06:18:05.971989 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":6317967,"delete_count":0,"lbm_write_time_us":6358,"lbm_writes_lt_1ms":157,"reinsert_count":0,"update_count":770}
I20260812 06:18:05.972448 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:05.983731 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":1887302,"delete_count":0,"lbm_write_time_us":3461,"lbm_writes_lt_1ms":49,"reinsert_count":0,"update_count":230}
I20260812 06:18:05.984206 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:06.154735 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.170s	user 0.136s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877284,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2609,"lbm_read_time_us":12059,"lbm_reads_lt_1ms":670,"lbm_write_time_us":34868,"lbm_writes_lt_1ms":643,"mutex_wait_us":57,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2432,"thread_start_us":86,"threads_started":1,"update_count":3000}
I20260812 06:18:06.155592 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=14.095187
I20260812 06:18:06.205075 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.049s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25911,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:06.205579 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=2.188937
I20260812 06:18:06.224521 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: FlushDeltaMemStoresOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.019s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5654,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:06.225087 25769 maintenance_manager.cc:419] P bfa6093e298642ca8d7bead1fa4a3f78: Scheduling MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e): perf score=1.000000
I20260812 06:18:06.235049 25567 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.968s	user 1.843s	sys 0.147s
I20260812 06:18:06.285976 25567 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.050s	user 0.001s	sys 0.000s
I20260812 06:18:06.286623 25567 tablet_server.cc:179] TabletServer@127.24.247.193:0 shutting down...
I20260812 06:18:06.349875 25703 maintenance_manager.cc:643] P bfa6093e298642ca8d7bead1fa4a3f78: MajorDeltaCompactionOp(a93ad22d63f549fab97ccd5aea32c21e) complete. Timing: real 0.125s	user 0.108s	sys 0.013s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1260,"lbm_read_time_us":8796,"lbm_reads_lt_1ms":560,"lbm_write_time_us":26721,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":37504,"update_count":2500}
I20260812 06:18:06.350638 25567 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:06.351029 25567 tablet_replica.cc:333] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78: stopping tablet replica
I20260812 06:18:06.351263 25567 raft_consensus.cc:2243] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:06.351596 25567 raft_consensus.cc:2272] T a93ad22d63f549fab97ccd5aea32c21e P bfa6093e298642ca8d7bead1fa4a3f78 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:06.369572 25567 tablet_server.cc:196] TabletServer@127.24.247.193:0 shutdown complete.
I20260812 06:18:06.396166 25567 master.cc:562] Master@127.24.247.254:40303 shutting down...
I20260812 06:18:06.400347 25567 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:06.400570 25567 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:06.400674 25567 tablet_replica.cc:333] T 00000000000000000000000000000000 P 54b3b75cf4154a27a10522ca7e0f93ef: stopping tablet replica
I20260812 06:18:06.413102 25567 master.cc:584] Master@127.24.247.254:40303 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5500 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:06.501914 25567 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.247.254:38571
I20260812 06:18:06.502337 25567 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:06.504652 25807 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:06.504706 25806 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:06.504706 25811 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:06.504858 25567 server_base.cc:1061] running on GCE node
I20260812 06:18:06.505043 25567 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:06.505093 25567 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:06.505110 25567 hybrid_clock.cc:648] HybridClock initialized: now 1786515486505110 us; error 0 us; skew 500 ppm
I20260812 06:18:06.506001 25567 webserver.cc:533] Webserver started at http://127.24.247.254:39825/ using document root <none> and password file <none>
I20260812 06:18:06.506189 25567 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:06.506246 25567 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:06.506346 25567 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:06.506753 25567 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/master-0-root/instance:
uuid: "6cf62a7756734af6bc85055923d65534"
format_stamp: "Formatted at 2026-08-12 06:18:06 on dist-test-slave-07c2"
I20260812 06:18:06.508392 25567 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:06.509347 25817 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:06.509598 25567 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:06.509689 25567 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/master-0-root
uuid: "6cf62a7756734af6bc85055923d65534"
format_stamp: "Formatted at 2026-08-12 06:18:06 on dist-test-slave-07c2"
I20260812 06:18:06.509778 25567 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-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:06.515486 25567 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:06.515828 25567 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:06.519773 25567 rpc_server.cc:307] RPC server started. Bound to: 127.24.247.254:38571
I20260812 06:18:06.521503 25879 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.247.254:38571 every 8 connection(s)
I20260812 06:18:06.522068 25880 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:06.534042 25880 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534: Bootstrap starting.
I20260812 06:18:06.534991 25880 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:06.536083 25880 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534: No bootstrap required, opened a new log
I20260812 06:18:06.536501 25880 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6cf62a7756734af6bc85055923d65534" member_type: VOTER }
I20260812 06:18:06.536630 25880 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:06.536700 25880 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6cf62a7756734af6bc85055923d65534, State: Initialized, Role: FOLLOWER
I20260812 06:18:06.536865 25880 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [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: "6cf62a7756734af6bc85055923d65534" member_type: VOTER }
I20260812 06:18:06.536936 25880 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:06.536998 25880 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:06.537057 25880 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:06.537748 25880 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6cf62a7756734af6bc85055923d65534" member_type: VOTER }
I20260812 06:18:06.537925 25880 leader_election.cc:304] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [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: 6cf62a7756734af6bc85055923d65534; no voters: 
I20260812 06:18:06.538125 25880 leader_election.cc:290] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:06.538250 25884 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:06.538496 25884 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [term 1 LEADER]: Becoming Leader. State: Replica: 6cf62a7756734af6bc85055923d65534, State: Running, Role: LEADER
I20260812 06:18:06.538604 25880 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:06.538657 25884 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [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: "6cf62a7756734af6bc85055923d65534" member_type: VOTER }
I20260812 06:18:06.539124 25887 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6cf62a7756734af6bc85055923d65534. Latest consensus state: current_term: 1 leader_uuid: "6cf62a7756734af6bc85055923d65534" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6cf62a7756734af6bc85055923d65534" member_type: VOTER } }
I20260812 06:18:06.539109 25886 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6cf62a7756734af6bc85055923d65534" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6cf62a7756734af6bc85055923d65534" member_type: VOTER } }
I20260812 06:18:06.539222 25887 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:06.539235 25886 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:06.539567 25890 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:06.540331 25890 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:06.540614 25567 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:06.542112 25890 catalog_manager.cc:1383] Generated new cluster ID: eafae2139f584d76ae5b669e0f167dc1
I20260812 06:18:06.542169 25890 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:06.568667 25890 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:06.569262 25890 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:06.580195 25890 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534: Generated new TSK 0
I20260812 06:18:06.580403 25890 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:06.605134 25567 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:06.607191 25911 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:06.607193 25908 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:06.607216 25907 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:06.607656 25567 server_base.cc:1061] running on GCE node
I20260812 06:18:06.607811 25567 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:06.607872 25567 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:06.607905 25567 hybrid_clock.cc:648] HybridClock initialized: now 1786515486607904 us; error 0 us; skew 500 ppm
I20260812 06:18:06.608758 25567 webserver.cc:533] Webserver started at http://127.24.247.193:36061/ using document root <none> and password file <none>
I20260812 06:18:06.608940 25567 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:06.609015 25567 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:06.609095 25567 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:06.609500 25567 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/instance:
uuid: "ef1629d6090744e6827be2e5c157a5ac"
format_stamp: "Formatted at 2026-08-12 06:18:06 on dist-test-slave-07c2"
I20260812 06:18:06.611123 25567 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:06.612218 25917 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:06.612481 25567 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:06.612550 25567 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root
uuid: "ef1629d6090744e6827be2e5c157a5ac"
format_stamp: "Formatted at 2026-08-12 06:18:06 on dist-test-slave-07c2"
I20260812 06:18:06.612635 25567 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-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:06.634397 25567 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:06.634809 25567 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:06.635134 25567 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:06.635669 25567 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:06.635710 25567 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:06.635743 25567 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:06.635758 25567 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:06.640275 25567 rpc_server.cc:307] RPC server started. Bound to: 127.24.247.193:36163
I20260812 06:18:06.640933 25992 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.247.193:36163 every 8 connection(s)
I20260812 06:18:06.650061 25993 heartbeater.cc:344] Connected to a master server at 127.24.247.254:38571
I20260812 06:18:06.650220 25993 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:06.650476 25993 heartbeater.cc:507] Master 127.24.247.254:38571 requested a full tablet report, sending...
I20260812 06:18:06.651173 25835 ts_manager.cc:194] Registered new tserver with Master: ef1629d6090744e6827be2e5c157a5ac (127.24.247.193:36163)
I20260812 06:18:06.652004 25835 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:53166
I20260812 06:18:06.652138 25567 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011069233s
I20260812 06:18:06.659603 25835 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:53168:
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:06.668419 25951 tablet_service.cc:1511] Processing CreateTablet for tablet ca758b1ff47348618fb8171612128e31 (DEFAULT_TABLE table=heavy-update-compaction-test [id=b6396665190f45fa8b1d461ea0b97ccf]), partition=
I20260812 06:18:06.668679 25951 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ca758b1ff47348618fb8171612128e31. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:06.670529 26007 tablet_bootstrap.cc:492] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Bootstrap starting.
I20260812 06:18:06.671591 26007 tablet_bootstrap.cc:654] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:06.672712 26007 tablet_bootstrap.cc:492] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: No bootstrap required, opened a new log
I20260812 06:18:06.672787 26007 ts_tablet_manager.cc:1403] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:06.673241 26007 raft_consensus.cc:359] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ef1629d6090744e6827be2e5c157a5ac" member_type: VOTER last_known_addr { host: "127.24.247.193" port: 36163 } }
I20260812 06:18:06.673332 26007 raft_consensus.cc:385] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:06.673388 26007 raft_consensus.cc:740] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ef1629d6090744e6827be2e5c157a5ac, State: Initialized, Role: FOLLOWER
I20260812 06:18:06.673571 26007 consensus_queue.cc:260] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac [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: "ef1629d6090744e6827be2e5c157a5ac" member_type: VOTER last_known_addr { host: "127.24.247.193" port: 36163 } }
I20260812 06:18:06.673669 26007 raft_consensus.cc:399] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:06.673727 26007 raft_consensus.cc:493] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:06.673790 26007 raft_consensus.cc:3060] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:06.674603 26007 raft_consensus.cc:515] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ef1629d6090744e6827be2e5c157a5ac" member_type: VOTER last_known_addr { host: "127.24.247.193" port: 36163 } }
I20260812 06:18:06.674753 26007 leader_election.cc:304] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac [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: ef1629d6090744e6827be2e5c157a5ac; no voters: 
I20260812 06:18:06.674979 26007 leader_election.cc:290] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:06.675140 26010 raft_consensus.cc:2804] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:06.675364 26007 ts_tablet_manager.cc:1434] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:06.675405 25993 heartbeater.cc:499] Master 127.24.247.254:38571 was elected leader, sending a full tablet report...
I20260812 06:18:06.675405 26010 raft_consensus.cc:697] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac [term 1 LEADER]: Becoming Leader. State: Replica: ef1629d6090744e6827be2e5c157a5ac, State: Running, Role: LEADER
I20260812 06:18:06.675786 26010 consensus_queue.cc:237] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac [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: "ef1629d6090744e6827be2e5c157a5ac" member_type: VOTER last_known_addr { host: "127.24.247.193" port: 36163 } }
I20260812 06:18:06.677106 25835 catalog_manager.cc:5719] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac reported cstate change: term changed from 0 to 1, leader changed from <none> to ef1629d6090744e6827be2e5c157a5ac (127.24.247.193). New cstate: current_term: 1 leader_uuid: "ef1629d6090744e6827be2e5c157a5ac" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ef1629d6090744e6827be2e5c157a5ac" member_type: VOTER last_known_addr { host: "127.24.247.193" port: 36163 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:06.735095 25567 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.014s	sys 0.008s
I20260812 06:18:06.891594 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushMRSOp(ca758b1ff47348618fb8171612128e31): perf score=19.054940
I20260812 06:18:07.040170 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushMRSOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.148s	user 0.106s	sys 0.040s Metrics: {"bytes_written":13333097,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":894,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40022,"lbm_writes_lt_1ms":782,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":3456,"update_count":1625}
I20260812 06:18:07.040756 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling LogGCOp(ca758b1ff47348618fb8171612128e31): free 20743831 bytes of WAL
I20260812 06:18:07.041008 25923 log_reader.cc:385] T ca758b1ff47348618fb8171612128e31: removed 2 log segments from log reader
I20260812 06:18:07.041074 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000001 (ops 1-6)
I20260812 06:18:07.041128 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000002 (ops 7-11)
I20260812 06:18:07.045552 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: LogGCOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:07.045899 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling UndoDeltaBlockGCOp(ca758b1ff47348618fb8171612128e31): 16411393 bytes on disk
I20260812 06:18:07.046299 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: UndoDeltaBlockGCOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:18:07.046669 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:07.062467 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.016s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3487284,"delete_count":0,"lbm_write_time_us":3422,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:18:07.062918 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:07.072662 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3655,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:07.073159 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:07.244508 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.171s	user 0.127s	sys 0.031s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774786,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":964,"lbm_read_time_us":10597,"lbm_reads_lt_1ms":569,"lbm_write_time_us":31164,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"thread_start_us":359,"threads_started":5,"update_count":2500}
I20260812 06:18:07.245048 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=14.095187
I20260812 06:18:07.298285 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.053s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21909,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:07.298774 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:07.309417 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3996,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:07.309872 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:07.467273 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.157s	user 0.133s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":499,"lbm_read_time_us":10895,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31451,"lbm_writes_lt_1ms":543,"mutex_wait_us":175,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":2500}
I20260812 06:18:07.468086 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=10.126437
I20260812 06:18:07.502903 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.035s	user 0.020s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15367,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:07.503501 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:07.520390 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.017s	user 0.006s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6443,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:07.520881 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:07.681299 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.160s	user 0.102s	sys 0.056s 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":126,"lbm_read_time_us":10828,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26737,"lbm_writes_lt_1ms":443,"mutex_wait_us":340,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:07.682760 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=10.126437
I20260812 06:18:07.715938 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.032s	user 0.010s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14104,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:07.716440 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:07.729240 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4605,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:07.729693 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:07.875347 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.145s	user 0.077s	sys 0.065s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":381,"lbm_read_time_us":9510,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23974,"lbm_writes_lt_1ms":443,"mutex_wait_us":86,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:18:07.876133 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=10.126437
I20260812 06:18:07.918285 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.042s	user 0.012s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15016,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:07.918752 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:07.929930 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.011s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4043,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:07.930619 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:08.059588 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.129s	user 0.101s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":133,"lbm_read_time_us":9378,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24064,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:18:08.060231 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=10.126437
I20260812 06:18:08.105405 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.045s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14639,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:08.105967 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:08.121440 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5721,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.122038 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:08.253170 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.131s	user 0.103s	sys 0.028s 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":175,"lbm_read_time_us":8350,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24256,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:08.253961 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=10.126437
I20260812 06:18:08.307067 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.053s	user 0.015s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15191,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:08.307683 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:08.319506 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4633,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.320043 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushMRSOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:08.366927 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushMRSOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.047s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1563,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1690,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:08.367602 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling LogGCOp(ca758b1ff47348618fb8171612128e31): free 124710289 bytes of WAL
I20260812 06:18:08.367838 25923 log_reader.cc:385] T ca758b1ff47348618fb8171612128e31: removed 12 log segments from log reader
I20260812 06:18:08.367884 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000003 (ops 12-16)
I20260812 06:18:08.367936 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000004 (ops 17-21)
I20260812 06:18:08.367983 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000005 (ops 22-26)
I20260812 06:18:08.368027 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000006 (ops 27-31)
I20260812 06:18:08.368070 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000007 (ops 32-36)
I20260812 06:18:08.368113 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000008 (ops 37-41)
I20260812 06:18:08.368153 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000009 (ops 42-46)
I20260812 06:18:08.368197 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000010 (ops 47-51)
I20260812 06:18:08.368238 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000011 (ops 52-56)
I20260812 06:18:08.368280 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000012 (ops 57-61)
I20260812 06:18:08.368320 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000013 (ops 62-66)
I20260812 06:18:08.368359 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000014 (ops 67-71)
I20260812 06:18:08.395166 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: LogGCOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:18:08.395583 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling UndoDeltaBlockGCOp(ca758b1ff47348618fb8171612128e31): 473 bytes on disk
I20260812 06:18:08.396034 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: UndoDeltaBlockGCOp(ca758b1ff47348618fb8171612128e31) 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:08.396621 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=3.181125
I20260812 06:18:08.418952 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.022s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512904,"delete_count":0,"lbm_write_time_us":7083,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:08.419461 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:08.429333 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3698,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:08.429780 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:08.641549 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.212s	user 0.120s	sys 0.091s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877330,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":532,"lbm_read_time_us":12548,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37934,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15488,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:18:08.642304 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=14.095187
I20260812 06:18:08.686267 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.044s	user 0.032s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19512,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:08.686743 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:08.846333 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.159s	user 0.133s	sys 0.020s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":678,"lbm_read_time_us":10763,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26118,"lbm_writes_lt_1ms":443,"mutex_wait_us":296,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:18:08.847029 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=11.118625
I20260812 06:18:08.883543 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.036s	user 0.033s	sys 0.003s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15753,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:08.884531 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:08.898332 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5178,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:08.898886 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:09.032024 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.133s	user 0.114s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":224,"lbm_read_time_us":7485,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23999,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:18:09.032610 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=10.126437
I20260812 06:18:09.064337 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.031s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13941,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:09.064991 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:09.076555 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4202,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.077190 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:09.208422 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.131s	user 0.106s	sys 0.025s 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":536,"lbm_read_time_us":9746,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25058,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2000}
I20260812 06:18:09.209163 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=10.126437
I20260812 06:18:09.255712 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.046s	user 0.030s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16464,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:09.256206 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:09.266911 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3938,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.267627 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:09.390391 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.123s	user 0.103s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":613,"lbm_read_time_us":8562,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24178,"lbm_writes_lt_1ms":443,"mutex_wait_us":319,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2000}
I20260812 06:18:09.390956 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=11.118625
I20260812 06:18:09.431981 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.041s	user 0.029s	sys 0.011s Metrics: {"bytes_written":12430564,"delete_count":0,"lbm_write_time_us":13995,"lbm_writes_lt_1ms":306,"reinsert_count":0,"update_count":1515}
I20260812 06:18:09.432554 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:09.444367 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":3848,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:18:09.445740 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:09.598920 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.153s	user 0.117s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":349,"lbm_read_time_us":10512,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26679,"lbm_writes_lt_1ms":443,"mutex_wait_us":103,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:09.599673 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=10.126437
I20260812 06:18:09.632802 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.033s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14598,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:09.633275 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:09.655649 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.022s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6157,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.656297 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:09.791335 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.135s	user 0.081s	sys 0.047s 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":1666,"lbm_read_time_us":8877,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24153,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:09.792204 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=11.118625
I20260812 06:18:09.842964 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.051s	user 0.024s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":24640,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:18:09.843569 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:09.861807 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.018s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6342,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.862298 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:09.871577 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3492,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:09.872071 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushMRSOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:09.901286 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushMRSOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.029s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":1586,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1480,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:09.901953 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling LogGCOp(ca758b1ff47348618fb8171612128e31): free 124257313 bytes of WAL
I20260812 06:18:09.902177 25923 log_reader.cc:385] T ca758b1ff47348618fb8171612128e31: removed 12 log segments from log reader
I20260812 06:18:09.902226 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000015 (ops 72-76)
I20260812 06:18:09.902256 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000016 (ops 77-81)
I20260812 06:18:09.902320 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000017 (ops 82-86)
I20260812 06:18:09.902351 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000018 (ops 87-91)
I20260812 06:18:09.902390 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000019 (ops 92-96)
I20260812 06:18:09.902451 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000020 (ops 97-100)
I20260812 06:18:09.902493 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000021 (ops 101-105)
I20260812 06:18:09.902531 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000022 (ops 106-110)
I20260812 06:18:09.902570 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000023 (ops 111-115)
I20260812 06:18:09.902607 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000024 (ops 116-120)
I20260812 06:18:09.902647 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000025 (ops 121-125)
I20260812 06:18:09.902684 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000026 (ops 126-130)
I20260812 06:18:09.929838 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: LogGCOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:09.930362 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=3.181125
I20260812 06:18:09.948292 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.018s	user 0.008s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7122,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:09.948805 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling UndoDeltaBlockGCOp(ca758b1ff47348618fb8171612128e31): 482 bytes on disk
I20260812 06:18:09.949235 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: UndoDeltaBlockGCOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:18:09.949716 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:09.960373 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4050,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:09.961228 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:10.171442 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.210s	user 0.156s	sys 0.042s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979851,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":439,"lbm_read_time_us":13280,"lbm_reads_lt_1ms":775,"lbm_write_time_us":38896,"lbm_writes_lt_1ms":743,"mutex_wait_us":26,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17920,"thread_start_us":110,"threads_started":1,"update_count":3500}
I20260812 06:18:10.172154 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=18.063937
I20260812 06:18:10.249981 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.078s	user 0.049s	sys 0.026s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28878,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:10.250823 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:10.267637 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6332,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.268184 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:10.466513 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.198s	user 0.107s	sys 0.091s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1421,"lbm_read_time_us":12357,"lbm_reads_lt_1ms":668,"lbm_write_time_us":34211,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:18:10.467273 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=14.095187
I20260812 06:18:10.520068 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.053s	user 0.015s	sys 0.036s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18228,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.520866 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:10.540607 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.020s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6186,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.541476 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:10.705260 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.164s	user 0.119s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":571,"lbm_read_time_us":10306,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28216,"lbm_writes_lt_1ms":543,"mutex_wait_us":218,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:10.705957 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=14.095187
I20260812 06:18:10.757493 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.051s	user 0.019s	sys 0.030s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18616,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.758131 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:10.772593 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5736,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.773219 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:10.955005 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.182s	user 0.139s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":256,"lbm_read_time_us":11231,"lbm_reads_lt_1ms":568,"lbm_write_time_us":30092,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18176,"update_count":2500}
I20260812 06:18:10.955663 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=14.095187
I20260812 06:18:11.013897 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.058s	user 0.038s	sys 0.014s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":24179,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:11.014528 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:11.036525 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.022s	user 0.009s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4079,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.037140 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:11.208678 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.171s	user 0.105s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":279,"lbm_read_time_us":10491,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29652,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:18:11.209390 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=14.095187
I20260812 06:18:11.260407 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.051s	user 0.018s	sys 0.029s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21995,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:11.260936 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:11.272130 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4012,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.272606 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushMRSOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:11.307974 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushMRSOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.035s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":1424,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1504,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:11.308717 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling LogGCOp(ca758b1ff47348618fb8171612128e31): free 121006692 bytes of WAL
I20260812 06:18:11.308993 25923 log_reader.cc:385] T ca758b1ff47348618fb8171612128e31: removed 12 log segments from log reader
I20260812 06:18:11.309056 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000027 (ops 131-135)
I20260812 06:18:11.309094 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000028 (ops 136-140)
I20260812 06:18:11.309125 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000029 (ops 141-145)
I20260812 06:18:11.309152 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000030 (ops 146-150)
I20260812 06:18:11.309185 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000031 (ops 151-154)
I20260812 06:18:11.309218 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000032 (ops 155-159)
I20260812 06:18:11.309244 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000033 (ops 160-164)
I20260812 06:18:11.309278 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000034 (ops 165-169)
I20260812 06:18:11.309312 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000035 (ops 170-174)
I20260812 06:18:11.309340 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000036 (ops 175-179)
I20260812 06:18:11.309370 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000037 (ops 180-184)
I20260812 06:18:11.309401 25923 log.cc:1079] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: Deleting log segment in path: /tmp/dist-test-taskN929fr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515480990552-25567-0/minicluster-data/ts-0-root/wals/ca758b1ff47348618fb8171612128e31/wal-000000038 (ops 185-189)
I20260812 06:18:11.336712 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: LogGCOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:11.337092 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=3.181125
I20260812 06:18:11.360852 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.024s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6606,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:11.361364 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling UndoDeltaBlockGCOp(ca758b1ff47348618fb8171612128e31): 447 bytes on disk
I20260812 06:18:11.361792 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: UndoDeltaBlockGCOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:18:11.362417 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=2.188937
I20260812 06:18:11.372150 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3692,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:11.372689 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31): perf score=1.000000
I20260812 06:18:11.602988 25567 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.868s	user 1.788s	sys 0.158s
I20260812 06:18:11.622289 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: MajorDeltaCompactionOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.249s	user 0.170s	sys 0.077s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979742,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2636,"lbm_read_time_us":14931,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39651,"lbm_writes_lt_1ms":743,"mutex_wait_us":2071,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18816,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:18:11.623468 25994 maintenance_manager.cc:419] P ef1629d6090744e6827be2e5c157a5ac: Scheduling FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31): perf score=18.063937
I20260812 06:18:11.660498 25567 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.057s	user 0.005s	sys 0.003s
I20260812 06:18:11.661136 25567 tablet_server.cc:179] TabletServer@127.24.247.193:0 shutting down...
I20260812 06:18:11.681341 25923 maintenance_manager.cc:643] P ef1629d6090744e6827be2e5c157a5ac: FlushDeltaMemStoresOp(ca758b1ff47348618fb8171612128e31) complete. Timing: real 0.058s	user 0.039s	sys 0.016s Metrics: {"bytes_written":20512321,"delete_count":0,"lbm_write_time_us":26201,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:11.681859 25567 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:11.682122 25567 tablet_replica.cc:333] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac: stopping tablet replica
I20260812 06:18:11.682286 25567 raft_consensus.cc:2243] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:11.682439 25567 raft_consensus.cc:2272] T ca758b1ff47348618fb8171612128e31 P ef1629d6090744e6827be2e5c157a5ac [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:11.696173 25567 tablet_server.cc:196] TabletServer@127.24.247.193:0 shutdown complete.
I20260812 06:18:11.699142 25567 master.cc:562] Master@127.24.247.254:38571 shutting down...
I20260812 06:18:11.702606 25567 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:11.702759 25567 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:11.702809 25567 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6cf62a7756734af6bc85055923d65534: stopping tablet replica
I20260812 06:18:11.715225 25567 master.cc:584] Master@127.24.247.254:38571 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5299 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10801 ms total)

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