[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:30.013206 14270 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.239.190:41527
I20260812 06:17:30.014264 14270 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:30.014910 14270 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:30.021220 14278 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:30.021284 14270 server_base.cc:1061] running on GCE node
W20260812 06:17:30.021224 14282 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:30.021528 14280 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:30.022083 14270 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:30.022207 14270 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:30.022254 14270 hybrid_clock.cc:648] HybridClock initialized: now 1786515450022251 us; error 0 us; skew 500 ppm
I20260812 06:17:30.024063 14270 webserver.cc:533] Webserver started at http://127.13.239.190:34195/ using document root <none> and password file <none>
I20260812 06:17:30.024618 14270 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:30.024680 14270 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:30.024951 14270 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:30.026748 14270 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/master-0-root/instance:
uuid: "30bc93dd91184413bd548ee074f16eb8"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-tk9z"
I20260812 06:17:30.030304 14270 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:30.032642 14288 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:30.033730 14270 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:30.033891 14270 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/master-0-root
uuid: "30bc93dd91184413bd548ee074f16eb8"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-tk9z"
I20260812 06:17:30.034013 14270 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:30.047981 14270 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:30.048756 14270 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:30.048949 14270 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:30.057129 14374 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.239.190:41527 every 8 connection(s)
I20260812 06:17:30.057109 14270 rpc_server.cc:307] RPC server started. Bound to: 127.13.239.190:41527
I20260812 06:17:30.059654 14375 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:30.065378 14375 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8: Bootstrap starting.
I20260812 06:17:30.067843 14375 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:30.068753 14375 log.cc:826] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:30.070647 14375 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8: No bootstrap required, opened a new log
I20260812 06:17:30.073444 14375 raft_consensus.cc:359] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "30bc93dd91184413bd548ee074f16eb8" member_type: VOTER }
I20260812 06:17:30.073617 14375 raft_consensus.cc:385] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:30.073658 14375 raft_consensus.cc:740] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 30bc93dd91184413bd548ee074f16eb8, State: Initialized, Role: FOLLOWER
I20260812 06:17:30.074201 14375 consensus_queue.cc:260] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [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: "30bc93dd91184413bd548ee074f16eb8" member_type: VOTER }
I20260812 06:17:30.074343 14375 raft_consensus.cc:399] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:30.074451 14375 raft_consensus.cc:493] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:30.074568 14375 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:30.075350 14375 raft_consensus.cc:515] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "30bc93dd91184413bd548ee074f16eb8" member_type: VOTER }
I20260812 06:17:30.075747 14375 leader_election.cc:304] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [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: 30bc93dd91184413bd548ee074f16eb8; no voters: 
I20260812 06:17:30.076047 14375 leader_election.cc:290] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:30.076210 14385 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:30.076474 14385 raft_consensus.cc:697] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [term 1 LEADER]: Becoming Leader. State: Replica: 30bc93dd91184413bd548ee074f16eb8, State: Running, Role: LEADER
I20260812 06:17:30.076946 14385 consensus_queue.cc:237] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [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: "30bc93dd91184413bd548ee074f16eb8" member_type: VOTER }
I20260812 06:17:30.077163 14375 sys_catalog.cc:565] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:30.079118 14389 sys_catalog.cc:455] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 30bc93dd91184413bd548ee074f16eb8. Latest consensus state: current_term: 1 leader_uuid: "30bc93dd91184413bd548ee074f16eb8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "30bc93dd91184413bd548ee074f16eb8" member_type: VOTER } }
I20260812 06:17:30.079138 14386 sys_catalog.cc:455] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "30bc93dd91184413bd548ee074f16eb8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "30bc93dd91184413bd548ee074f16eb8" member_type: VOTER } }
I20260812 06:17:30.079303 14386 sys_catalog.cc:458] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:30.079303 14389 sys_catalog.cc:458] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:30.079697 14270 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:30.081664 14414 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:30.081730 14414 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:30.081808 14405 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:30.082664 14405 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:30.088301 14405 catalog_manager.cc:1383] Generated new cluster ID: 4263d2f6179b40eaab8afd844415452a
I20260812 06:17:30.088408 14405 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:30.095698 14405 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:30.096771 14405 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:30.116189 14405 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8: Generated new TSK 0
I20260812 06:17:30.116956 14405 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:30.144640 14270 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:30.147354 14422 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:30.147464 14428 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:30.147485 14424 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:30.147997 14270 server_base.cc:1061] running on GCE node
I20260812 06:17:30.148195 14270 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:30.148236 14270 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:30.148257 14270 hybrid_clock.cc:648] HybridClock initialized: now 1786515450148256 us; error 0 us; skew 500 ppm
I20260812 06:17:30.149268 14270 webserver.cc:533] Webserver started at http://127.13.239.129:46603/ using document root <none> and password file <none>
I20260812 06:17:30.149492 14270 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:30.149555 14270 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:30.149641 14270 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:30.150038 14270 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/instance:
uuid: "157ab129300449bfae68248fbcbe784c"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-tk9z"
I20260812 06:17:30.151710 14270 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:17:30.152748 14441 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:30.153015 14270 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:30.153087 14270 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root
uuid: "157ab129300449bfae68248fbcbe784c"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-tk9z"
I20260812 06:17:30.153178 14270 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:30.166468 14270 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:30.166982 14270 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:30.167565 14270 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:30.168514 14270 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:30.168568 14270 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:30.168645 14270 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:30.168689 14270 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:30.175784 14270 rpc_server.cc:307] RPC server started. Bound to: 127.13.239.129:33205
I20260812 06:17:30.175850 14557 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.239.129:33205 every 8 connection(s)
I20260812 06:17:30.190656 14561 heartbeater.cc:344] Connected to a master server at 127.13.239.190:41527
I20260812 06:17:30.190937 14561 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:30.191473 14561 heartbeater.cc:507] Master 127.13.239.190:41527 requested a full tablet report, sending...
I20260812 06:17:30.193073 14317 ts_manager.cc:194] Registered new tserver with Master: 157ab129300449bfae68248fbcbe784c (127.13.239.129:33205)
I20260812 06:17:30.193434 14270 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016959489s
I20260812 06:17:30.194562 14317 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:42612
I20260812 06:17:30.204111 14317 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:42614:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:30.223572 14496 tablet_service.cc:1511] Processing CreateTablet for tablet 2f6b05111c954ba6ad4a099eb7331172 (DEFAULT_TABLE table=heavy-update-compaction-test [id=c65e68d317d743a39b09c15709c0ea1b]), partition=
I20260812 06:17:30.224128 14496 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 2f6b05111c954ba6ad4a099eb7331172. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:30.226436 14583 tablet_bootstrap.cc:492] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Bootstrap starting.
I20260812 06:17:30.227487 14583 tablet_bootstrap.cc:654] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:30.228948 14583 tablet_bootstrap.cc:492] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: No bootstrap required, opened a new log
I20260812 06:17:30.229063 14583 ts_tablet_manager.cc:1403] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:30.229565 14583 raft_consensus.cc:359] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "157ab129300449bfae68248fbcbe784c" member_type: VOTER last_known_addr { host: "127.13.239.129" port: 33205 } }
I20260812 06:17:30.229671 14583 raft_consensus.cc:385] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:30.229693 14583 raft_consensus.cc:740] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 157ab129300449bfae68248fbcbe784c, State: Initialized, Role: FOLLOWER
I20260812 06:17:30.229846 14583 consensus_queue.cc:260] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c [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: "157ab129300449bfae68248fbcbe784c" member_type: VOTER last_known_addr { host: "127.13.239.129" port: 33205 } }
I20260812 06:17:30.229934 14583 raft_consensus.cc:399] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:30.229991 14583 raft_consensus.cc:493] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:30.230049 14583 raft_consensus.cc:3060] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:30.230927 14583 raft_consensus.cc:515] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "157ab129300449bfae68248fbcbe784c" member_type: VOTER last_known_addr { host: "127.13.239.129" port: 33205 } }
I20260812 06:17:30.231092 14583 leader_election.cc:304] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c [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: 157ab129300449bfae68248fbcbe784c; no voters: 
I20260812 06:17:30.231328 14583 leader_election.cc:290] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:30.231475 14586 raft_consensus.cc:2804] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:30.231730 14586 raft_consensus.cc:697] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c [term 1 LEADER]: Becoming Leader. State: Replica: 157ab129300449bfae68248fbcbe784c, State: Running, Role: LEADER
I20260812 06:17:30.231760 14583 ts_tablet_manager.cc:1434] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:30.231906 14586 consensus_queue.cc:237] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c [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: "157ab129300449bfae68248fbcbe784c" member_type: VOTER last_known_addr { host: "127.13.239.129" port: 33205 } }
I20260812 06:17:30.232293 14561 heartbeater.cc:499] Master 127.13.239.190:41527 was elected leader, sending a full tablet report...
I20260812 06:17:30.234946 14317 catalog_manager.cc:5719] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c reported cstate change: term changed from 0 to 1, leader changed from <none> to 157ab129300449bfae68248fbcbe784c (127.13.239.129). New cstate: current_term: 1 leader_uuid: "157ab129300449bfae68248fbcbe784c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "157ab129300449bfae68248fbcbe784c" member_type: VOTER last_known_addr { host: "127.13.239.129" port: 33205 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:30.305413 14270 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.020s	sys 0.010s
I20260812 06:17:30.426962 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushMRSOp(2f6b05111c954ba6ad4a099eb7331172): perf score=15.086190
I20260812 06:17:30.598227 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushMRSOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.171s	user 0.130s	sys 0.036s Metrics: {"bytes_written":13292063,"cfile_init":1,"compiler_manager_pool.queue_time_us":323,"delete_count":0,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":189,"dirs.run_wall_time_us":757,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41336,"lbm_writes_lt_1ms":681,"mutex_wait_us":272,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":158592,"thread_start_us":120,"threads_started":1,"update_count":1620}
I20260812 06:17:30.599486 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling LogGCOp(2f6b05111c954ba6ad4a099eb7331172): free 11976772 bytes of WAL
I20260812 06:17:30.599797 14451 log_reader.cc:385] T 2f6b05111c954ba6ad4a099eb7331172: removed 1 log segments from log reader
I20260812 06:17:30.599854 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000001 (ops 1-6)
I20260812 06:17:30.603113 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: LogGCOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:30.603647 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling UndoDeltaBlockGCOp(2f6b05111c954ba6ad4a099eb7331172): 12308958 bytes on disk
I20260812 06:17:30.604269 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: UndoDeltaBlockGCOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:17:30.604698 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=3.181125
I20260812 06:17:30.622649 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.018s	user 0.013s	sys 0.004s Metrics: {"bytes_written":5210314,"delete_count":0,"lbm_write_time_us":7399,"lbm_writes_lt_1ms":130,"reinsert_count":0,"update_count":635}
I20260812 06:17:30.623240 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:30.631697 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2010377,"delete_count":0,"lbm_write_time_us":2730,"lbm_writes_lt_1ms":52,"reinsert_count":0,"update_count":245}
I20260812 06:17:30.632172 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:30.822127 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.190s	user 0.129s	sys 0.049s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733790,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":517,"lbm_read_time_us":11880,"lbm_reads_lt_1ms":569,"lbm_write_time_us":30317,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"thread_start_us":325,"threads_started":5,"update_count":2500}
I20260812 06:17:30.822777 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=14.095187
I20260812 06:17:30.870213 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.047s	user 0.026s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19531,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.870893 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:30.882421 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4000,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.882915 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:31.042274 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.159s	user 0.124s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":886,"lbm_read_time_us":11461,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31603,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22784,"update_count":2500}
I20260812 06:17:31.042930 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=10.126437
I20260812 06:17:31.090730 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.048s	user 0.024s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19368,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:31.091464 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:31.118680 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.027s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5805,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.119135 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:31.129770 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3909,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.130234 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:31.290724 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.160s	user 0.106s	sys 0.042s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733843,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":383,"lbm_read_time_us":10728,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30190,"lbm_writes_lt_1ms":543,"mutex_wait_us":100,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:31.291332 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=14.095187
I20260812 06:17:31.350198 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.059s	user 0.034s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24240,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.350883 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:31.363566 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4306,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.364329 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:31.535907 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.171s	user 0.125s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":383,"lbm_read_time_us":12581,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34724,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":735616,"update_count":2500}
I20260812 06:17:31.536675 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=11.118625
I20260812 06:17:31.575258 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.038s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16548,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:31.576098 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:31.595378 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.019s	user 0.005s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6062,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:31.595837 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:31.716460 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.120s	user 0.088s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":987,"lbm_read_time_us":7660,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24361,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.717217 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=11.118625
I20260812 06:17:31.761917 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.044s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15667,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:31.762579 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:31.775544 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4189,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:31.776245 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushMRSOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:31.807121 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushMRSOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.031s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":97,"dirs.run_cpu_time_us":317,"dirs.run_wall_time_us":1611,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1926,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:31.808348 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling LogGCOp(2f6b05111c954ba6ad4a099eb7331172): free 117302580 bytes of WAL
I20260812 06:17:31.808673 14451 log_reader.cc:385] T 2f6b05111c954ba6ad4a099eb7331172: removed 12 log segments from log reader
I20260812 06:17:31.808755 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000002 (ops 7-11)
I20260812 06:17:31.808811 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000003 (ops 12-16)
I20260812 06:17:31.808879 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000004 (ops 17-21)
I20260812 06:17:31.808921 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000005 (ops 22-26)
I20260812 06:17:31.808956 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000006 (ops 27-30)
I20260812 06:17:31.808996 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000007 (ops 31-35)
I20260812 06:17:31.809034 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000008 (ops 36-40)
I20260812 06:17:31.809077 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000009 (ops 41-45)
I20260812 06:17:31.809114 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000010 (ops 46-50)
I20260812 06:17:31.809152 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000011 (ops 51-54)
I20260812 06:17:31.809190 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000012 (ops 55-59)
I20260812 06:17:31.809226 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000013 (ops 60-64)
I20260812 06:17:31.837838 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: LogGCOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:31.838284 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling UndoDeltaBlockGCOp(2f6b05111c954ba6ad4a099eb7331172): 448 bytes on disk
I20260812 06:17:31.839015 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: UndoDeltaBlockGCOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:17:31.839501 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=6.157687
I20260812 06:17:31.858974 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.019s	user 0.015s	sys 0.004s Metrics: {"bytes_written":7589714,"delete_count":0,"lbm_write_time_us":7665,"lbm_writes_lt_1ms":188,"reinsert_count":0,"update_count":925}
I20260812 06:17:31.859661 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:32.048174 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.188s	user 0.120s	sys 0.068s Metrics: {"cfile_cache_miss":618,"cfile_cache_miss_bytes":28220883,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":773,"lbm_read_time_us":13037,"lbm_reads_lt_1ms":654,"lbm_write_time_us":31714,"lbm_writes_lt_1ms":628,"mutex_wait_us":351,"peak_mem_usage":72846179,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":109,"threads_started":1,"update_count":2925}
I20260812 06:17:32.048923 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=15.087375
I20260812 06:17:32.111253 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.062s	user 0.043s	sys 0.008s Metrics: {"bytes_written":17025269,"delete_count":0,"lbm_write_time_us":22676,"lbm_writes_lt_1ms":418,"reinsert_count":0,"update_count":2075}
I20260812 06:17:32.111842 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:32.127525 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5684,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.128010 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:32.306700 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.179s	user 0.116s	sys 0.060s Metrics: {"cfile_cache_miss":547,"cfile_cache_miss_bytes":25349091,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":659,"lbm_read_time_us":12082,"lbm_reads_lt_1ms":587,"lbm_write_time_us":31716,"lbm_writes_lt_1ms":558,"mutex_wait_us":24,"peak_mem_usage":64771809,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2575}
I20260812 06:17:32.307297 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=14.095187
I20260812 06:17:32.360612 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.053s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":22609,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.361109 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:32.373464 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4285,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.374065 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:32.545754 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.171s	user 0.097s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733721,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":297,"lbm_read_time_us":11542,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29728,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:17:32.546502 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=14.095187
I20260812 06:17:32.610082 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.063s	user 0.031s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24365,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.610728 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:32.621654 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4360,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.622119 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:32.793051 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.171s	user 0.123s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":139,"lbm_read_time_us":13074,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30162,"lbm_writes_lt_1ms":543,"mutex_wait_us":6,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:17:32.793656 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=11.118625
I20260812 06:17:32.837529 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.044s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18184,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:32.838115 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:32.865540 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.027s	user 0.012s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6724,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.866055 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:32.876190 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3834,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:32.876816 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:33.068650 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.192s	user 0.129s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":905,"lbm_read_time_us":14346,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32159,"lbm_writes_lt_1ms":543,"mutex_wait_us":306,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2500}
I20260812 06:17:33.069259 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=11.118625
I20260812 06:17:33.101189 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.032s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13926,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:33.102185 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:33.130592 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.028s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5708,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.131076 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:33.142427 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4394,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.143278 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:33.348696 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.205s	user 0.131s	sys 0.057s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":173,"lbm_read_time_us":13893,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31608,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25856,"update_count":2500}
I20260812 06:17:33.349464 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=14.095187
I20260812 06:17:33.402568 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.053s	user 0.029s	sys 0.022s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25892,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.403062 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:33.415016 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4127,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.415668 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushMRSOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:33.451957 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushMRSOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.036s	user 0.030s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1168,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2102,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:33.452832 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling LogGCOp(2f6b05111c954ba6ad4a099eb7331172): free 132118263 bytes of WAL
I20260812 06:17:33.453123 14451 log_reader.cc:385] T 2f6b05111c954ba6ad4a099eb7331172: removed 13 log segments from log reader
I20260812 06:17:33.453187 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000014 (ops 65-68)
I20260812 06:17:33.453224 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000015 (ops 69-73)
I20260812 06:17:33.453248 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000016 (ops 74-78)
I20260812 06:17:33.453274 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000017 (ops 79-82)
I20260812 06:17:33.453310 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000018 (ops 83-87)
I20260812 06:17:33.453342 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000019 (ops 88-92)
I20260812 06:17:33.453364 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000020 (ops 93-96)
I20260812 06:17:33.453387 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000021 (ops 97-101)
I20260812 06:17:33.453408 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000022 (ops 102-106)
I20260812 06:17:33.453430 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000023 (ops 107-111)
I20260812 06:17:33.453456 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000024 (ops 112-116)
I20260812 06:17:33.453481 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000025 (ops 117-121)
I20260812 06:17:33.453503 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000026 (ops 122-126)
I20260812 06:17:33.486605 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: LogGCOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.034s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:17:33.487759 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling UndoDeltaBlockGCOp(2f6b05111c954ba6ad4a099eb7331172): 492 bytes on disk
I20260812 06:17:33.488384 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: UndoDeltaBlockGCOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:17:33.488991 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=3.181125
I20260812 06:17:33.504297 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.015s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4776,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:33.504813 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:33.514982 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3828,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.515446 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:33.757340 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.242s	user 0.155s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938773,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":853,"lbm_read_time_us":16115,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39654,"lbm_writes_lt_1ms":743,"mutex_wait_us":71,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12032,"thread_start_us":91,"threads_started":1,"update_count":3500}
I20260812 06:17:33.758188 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=18.063937
I20260812 06:17:33.825691 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.067s	user 0.032s	sys 0.032s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":30766,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:33.826169 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:33.838162 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3863,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.839277 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:34.049649 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.210s	user 0.141s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836141,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1074,"lbm_read_time_us":13325,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34369,"lbm_writes_lt_1ms":643,"mutex_wait_us":29,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:17:34.050868 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=16.079562
I20260812 06:17:34.104262 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.053s	user 0.039s	sys 0.012s Metrics: {"bytes_written":17640625,"delete_count":0,"lbm_write_time_us":23222,"lbm_writes_lt_1ms":433,"reinsert_count":0,"update_count":2150}
I20260812 06:17:34.104878 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:34.128569 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3282159,"delete_count":0,"lbm_write_time_us":5073,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:17:34.129031 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:34.138883 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3629,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.139397 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:34.362223 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.223s	user 0.154s	sys 0.068s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836224,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":243,"lbm_read_time_us":14961,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36732,"lbm_writes_lt_1ms":643,"mutex_wait_us":85,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":3000}
I20260812 06:17:34.362833 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=14.095187
I20260812 06:17:34.417778 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.055s	user 0.026s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22050,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.418341 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:34.561445 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.143s	user 0.090s	sys 0.053s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":948,"lbm_read_time_us":9494,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22251,"lbm_writes_lt_1ms":443,"mutex_wait_us":344,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:17:34.562139 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=14.095187
I20260812 06:17:34.616737 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.054s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21316,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.617266 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:34.633287 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5981,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.634001 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:34.834816 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.201s	user 0.108s	sys 0.084s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":820,"lbm_read_time_us":12189,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32289,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2500}
I20260812 06:17:34.835350 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=14.095187
I20260812 06:17:34.890825 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.055s	user 0.017s	sys 0.033s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22667,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.891325 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:34.903697 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4224,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.904376 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushMRSOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:34.935330 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushMRSOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.031s	user 0.029s	sys 0.001s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":1158,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1917,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:34.936129 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling LogGCOp(2f6b05111c954ba6ad4a099eb7331172): free 120553636 bytes of WAL
I20260812 06:17:34.936406 14451 log_reader.cc:385] T 2f6b05111c954ba6ad4a099eb7331172: removed 12 log segments from log reader
I20260812 06:17:34.936465 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000027 (ops 127-131)
I20260812 06:17:34.936504 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000028 (ops 132-136)
I20260812 06:17:34.936542 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000029 (ops 137-141)
I20260812 06:17:34.936565 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000030 (ops 142-146)
I20260812 06:17:34.936597 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000031 (ops 147-150)
I20260812 06:17:34.936625 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000032 (ops 151-155)
I20260812 06:17:34.936655 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000033 (ops 156-160)
I20260812 06:17:34.936689 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000034 (ops 161-165)
I20260812 06:17:34.936720 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000035 (ops 166-170)
I20260812 06:17:34.936748 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000036 (ops 171-175)
I20260812 06:17:34.936779 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000037 (ops 176-180)
I20260812 06:17:34.936806 14451 log.cc:1079] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/2f6b05111c954ba6ad4a099eb7331172/wal-000000038 (ops 181-184)
I20260812 06:17:34.966990 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: LogGCOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:34.967592 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling UndoDeltaBlockGCOp(2f6b05111c954ba6ad4a099eb7331172): 448 bytes on disk
I20260812 06:17:34.968130 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: UndoDeltaBlockGCOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:17:34.975055 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:34.994237 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.019s	user 0.004s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4456,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.994891 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=2.188937
I20260812 06:17:35.007092 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4587,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.007653 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:35.240721 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.233s	user 0.152s	sys 0.079s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938787,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":856,"lbm_read_time_us":15469,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37908,"lbm_writes_lt_1ms":743,"mutex_wait_us":75,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:17:35.241678 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172): perf score=18.063937
I20260812 06:17:35.315033 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: FlushDeltaMemStoresOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.073s	user 0.034s	sys 0.035s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":31428,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:35.315549 14562 maintenance_manager.cc:419] P 157ab129300449bfae68248fbcbe784c: Scheduling MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172): perf score=1.000000
I20260812 06:17:35.385298 14270 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.080s	user 1.831s	sys 0.198s
I20260812 06:17:35.448437 14270 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.062s	user 0.002s	sys 0.000s
I20260812 06:17:35.449105 14270 tablet_server.cc:179] TabletServer@127.13.239.129:0 shutting down...
I20260812 06:17:35.474277 14451 maintenance_manager.cc:643] P 157ab129300449bfae68248fbcbe784c: MajorDeltaCompactionOp(2f6b05111c954ba6ad4a099eb7331172) complete. Timing: real 0.159s	user 0.105s	sys 0.052s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24733607,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":332,"lbm_read_time_us":13516,"lbm_reads_lt_1ms":559,"lbm_write_time_us":24531,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:17:35.475093 14270 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:35.475519 14270 tablet_replica.cc:333] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c: stopping tablet replica
I20260812 06:17:35.475793 14270 raft_consensus.cc:2243] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:35.476052 14270 raft_consensus.cc:2272] T 2f6b05111c954ba6ad4a099eb7331172 P 157ab129300449bfae68248fbcbe784c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:35.494009 14270 tablet_server.cc:196] TabletServer@127.13.239.129:0 shutdown complete.
I20260812 06:17:35.521085 14270 master.cc:562] Master@127.13.239.190:41527 shutting down...
I20260812 06:17:35.525241 14270 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:35.525451 14270 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:35.525550 14270 tablet_replica.cc:333] T 00000000000000000000000000000000 P 30bc93dd91184413bd548ee074f16eb8: stopping tablet replica
I20260812 06:17:35.538064 14270 master.cc:584] Master@127.13.239.190:41527 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5620 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:35.647310 14270 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.239.190:45431
I20260812 06:17:35.647733 14270 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:35.650233 14624 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:35.650286 14623 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:35.650321 14631 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:35.650363 14270 server_base.cc:1061] running on GCE node
I20260812 06:17:35.650743 14270 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:35.650803 14270 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:35.650820 14270 hybrid_clock.cc:648] HybridClock initialized: now 1786515455650819 us; error 0 us; skew 500 ppm
I20260812 06:17:35.651739 14270 webserver.cc:533] Webserver started at http://127.13.239.190:35705/ using document root <none> and password file <none>
I20260812 06:17:35.651947 14270 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:35.652004 14270 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:35.652107 14270 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:35.652554 14270 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/master-0-root/instance:
uuid: "9856d490270a4ceeaf4b9a2010b88bd0"
format_stamp: "Formatted at 2026-08-12 06:17:35 on dist-test-slave-tk9z"
I20260812 06:17:35.654186 14270 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:35.655277 14643 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:35.655544 14270 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:35.655611 14270 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/master-0-root
uuid: "9856d490270a4ceeaf4b9a2010b88bd0"
format_stamp: "Formatted at 2026-08-12 06:17:35 on dist-test-slave-tk9z"
I20260812 06:17:35.655699 14270 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:35.677062 14270 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:35.677531 14270 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:35.682271 14270 rpc_server.cc:307] RPC server started. Bound to: 127.13.239.190:45431
I20260812 06:17:35.683766 14748 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.239.190:45431 every 8 connection(s)
I20260812 06:17:35.684442 14749 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:35.688467 14749 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0: Bootstrap starting.
I20260812 06:17:35.689337 14749 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:35.690472 14749 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0: No bootstrap required, opened a new log
I20260812 06:17:35.690861 14749 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9856d490270a4ceeaf4b9a2010b88bd0" member_type: VOTER }
I20260812 06:17:35.690948 14749 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:35.690970 14749 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9856d490270a4ceeaf4b9a2010b88bd0, State: Initialized, Role: FOLLOWER
I20260812 06:17:35.691075 14749 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [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: "9856d490270a4ceeaf4b9a2010b88bd0" member_type: VOTER }
I20260812 06:17:35.691131 14749 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:35.691154 14749 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:35.691190 14749 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:35.691820 14749 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9856d490270a4ceeaf4b9a2010b88bd0" member_type: VOTER }
I20260812 06:17:35.691933 14749 leader_election.cc:304] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [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: 9856d490270a4ceeaf4b9a2010b88bd0; no voters: 
I20260812 06:17:35.692080 14749 leader_election.cc:290] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:35.692265 14757 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:35.692502 14757 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [term 1 LEADER]: Becoming Leader. State: Replica: 9856d490270a4ceeaf4b9a2010b88bd0, State: Running, Role: LEADER
I20260812 06:17:35.692561 14749 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:35.692648 14757 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [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: "9856d490270a4ceeaf4b9a2010b88bd0" member_type: VOTER }
I20260812 06:17:35.693159 14762 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9856d490270a4ceeaf4b9a2010b88bd0. Latest consensus state: current_term: 1 leader_uuid: "9856d490270a4ceeaf4b9a2010b88bd0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9856d490270a4ceeaf4b9a2010b88bd0" member_type: VOTER } }
I20260812 06:17:35.693145 14761 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9856d490270a4ceeaf4b9a2010b88bd0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9856d490270a4ceeaf4b9a2010b88bd0" member_type: VOTER } }
I20260812 06:17:35.693310 14762 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:35.693331 14761 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:35.693639 14773 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:35.694662 14773 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:35.694888 14270 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:35.696645 14773 catalog_manager.cc:1383] Generated new cluster ID: 0d1523511cdf4d2eb4718abc4f5aa0aa
I20260812 06:17:35.696707 14773 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:35.702088 14773 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:35.702718 14773 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:35.710639 14773 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0: Generated new TSK 0
I20260812 06:17:35.710847 14773 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:35.727625 14270 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:35.729877 14800 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:35.729959 14270 server_base.cc:1061] running on GCE node
W20260812 06:17:35.730022 14797 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:35.730079 14794 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:35.730293 14270 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:35.730340 14270 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:35.730356 14270 hybrid_clock.cc:648] HybridClock initialized: now 1786515455730356 us; error 0 us; skew 500 ppm
I20260812 06:17:35.731324 14270 webserver.cc:533] Webserver started at http://127.13.239.129:34303/ using document root <none> and password file <none>
I20260812 06:17:35.731535 14270 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:35.731608 14270 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:35.731695 14270 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:35.732139 14270 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/instance:
uuid: "f5d05a91df25494fa4d2f9b398dc6a50"
format_stamp: "Formatted at 2026-08-12 06:17:35 on dist-test-slave-tk9z"
I20260812 06:17:35.733718 14270 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:35.734876 14808 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:35.735167 14270 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:35.735234 14270 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root
uuid: "f5d05a91df25494fa4d2f9b398dc6a50"
format_stamp: "Formatted at 2026-08-12 06:17:35 on dist-test-slave-tk9z"
I20260812 06:17:35.735330 14270 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:35.750344 14270 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:35.750914 14270 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:35.751260 14270 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:35.751775 14270 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:35.751812 14270 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:35.751847 14270 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:35.751863 14270 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:35.756392 14270 rpc_server.cc:307] RPC server started. Bound to: 127.13.239.129:41195
I20260812 06:17:35.756429 14916 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.239.129:41195 every 8 connection(s)
I20260812 06:17:35.766396 14918 heartbeater.cc:344] Connected to a master server at 127.13.239.190:45431
I20260812 06:17:35.766561 14918 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:35.766832 14918 heartbeater.cc:507] Master 127.13.239.190:45431 requested a full tablet report, sending...
I20260812 06:17:35.767529 14667 ts_manager.cc:194] Registered new tserver with Master: f5d05a91df25494fa4d2f9b398dc6a50 (127.13.239.129:41195)
I20260812 06:17:35.767983 14270 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011071248s
I20260812 06:17:35.768517 14667 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56874
I20260812 06:17:35.775888 14667 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56886:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:35.785379 14859 tablet_service.cc:1511] Processing CreateTablet for tablet 309150624deb497d9f952091e17dcc1a (DEFAULT_TABLE table=heavy-update-compaction-test [id=0d8a309c13af4fcc88bc15969e4cf54c]), partition=
I20260812 06:17:35.785643 14859 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 309150624deb497d9f952091e17dcc1a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:35.787747 14938 tablet_bootstrap.cc:492] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Bootstrap starting.
I20260812 06:17:35.788717 14938 tablet_bootstrap.cc:654] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:35.789881 14938 tablet_bootstrap.cc:492] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: No bootstrap required, opened a new log
I20260812 06:17:35.789961 14938 ts_tablet_manager.cc:1403] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:35.790438 14938 raft_consensus.cc:359] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f5d05a91df25494fa4d2f9b398dc6a50" member_type: VOTER last_known_addr { host: "127.13.239.129" port: 41195 } }
I20260812 06:17:35.790558 14938 raft_consensus.cc:385] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:35.790612 14938 raft_consensus.cc:740] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f5d05a91df25494fa4d2f9b398dc6a50, State: Initialized, Role: FOLLOWER
I20260812 06:17:35.790817 14938 consensus_queue.cc:260] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50 [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: "f5d05a91df25494fa4d2f9b398dc6a50" member_type: VOTER last_known_addr { host: "127.13.239.129" port: 41195 } }
I20260812 06:17:35.790923 14938 raft_consensus.cc:399] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:35.790971 14938 raft_consensus.cc:493] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:35.791029 14938 raft_consensus.cc:3060] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:35.791857 14938 raft_consensus.cc:515] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f5d05a91df25494fa4d2f9b398dc6a50" member_type: VOTER last_known_addr { host: "127.13.239.129" port: 41195 } }
I20260812 06:17:35.792037 14938 leader_election.cc:304] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50 [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: f5d05a91df25494fa4d2f9b398dc6a50; no voters: 
I20260812 06:17:35.792272 14938 leader_election.cc:290] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:35.792512 14944 raft_consensus.cc:2804] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:35.792660 14938 ts_tablet_manager.cc:1434] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:35.792673 14918 heartbeater.cc:499] Master 127.13.239.190:45431 was elected leader, sending a full tablet report...
I20260812 06:17:35.792737 14944 raft_consensus.cc:697] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50 [term 1 LEADER]: Becoming Leader. State: Replica: f5d05a91df25494fa4d2f9b398dc6a50, State: Running, Role: LEADER
I20260812 06:17:35.792894 14944 consensus_queue.cc:237] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50 [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: "f5d05a91df25494fa4d2f9b398dc6a50" member_type: VOTER last_known_addr { host: "127.13.239.129" port: 41195 } }
I20260812 06:17:35.794332 14667 catalog_manager.cc:5719] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50 reported cstate change: term changed from 0 to 1, leader changed from <none> to f5d05a91df25494fa4d2f9b398dc6a50 (127.13.239.129). New cstate: current_term: 1 leader_uuid: "f5d05a91df25494fa4d2f9b398dc6a50" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f5d05a91df25494fa4d2f9b398dc6a50" member_type: VOTER last_known_addr { host: "127.13.239.129" port: 41195 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:35.855896 14270 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.008s	sys 0.015s
I20260812 06:17:36.007469 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushMRSOp(309150624deb497d9f952091e17dcc1a): perf score=19.054940
I20260812 06:17:36.170604 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushMRSOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.163s	user 0.119s	sys 0.044s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":98,"dirs.run_cpu_time_us":264,"dirs.run_wall_time_us":828,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39118,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:17:36.171346 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling LogGCOp(309150624deb497d9f952091e17dcc1a): free 20743880 bytes of WAL
I20260812 06:17:36.171591 14813 log_reader.cc:385] T 309150624deb497d9f952091e17dcc1a: removed 2 log segments from log reader
I20260812 06:17:36.171644 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000001 (ops 1-6)
I20260812 06:17:36.171686 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000002 (ops 7-11)
I20260812 06:17:36.177100 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: LogGCOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:36.177569 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling UndoDeltaBlockGCOp(309150624deb497d9f952091e17dcc1a): 16411392 bytes on disk
I20260812 06:17:36.178108 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: UndoDeltaBlockGCOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:17:36.178683 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:36.189517 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4228,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.190012 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:36.359207 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.169s	user 0.097s	sys 0.060s 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":641,"lbm_read_time_us":11840,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26578,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":321,"threads_started":5,"update_count":2000}
I20260812 06:17:36.359905 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=14.095187
I20260812 06:17:36.423391 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.063s	user 0.039s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26749,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.423945 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:36.436697 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.013s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4549,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.437218 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:36.635393 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.198s	user 0.129s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":786,"lbm_read_time_us":11978,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30120,"lbm_writes_lt_1ms":543,"mutex_wait_us":303,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:36.636134 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=14.095187
I20260812 06:17:36.685559 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.049s	user 0.022s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21032,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.686031 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:36.699993 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4858,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.700497 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:36.862149 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.161s	user 0.105s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":149,"lbm_read_time_us":11573,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29437,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":26880,"update_count":2500}
I20260812 06:17:36.862839 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=14.095187
I20260812 06:17:36.914873 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.052s	user 0.041s	sys 0.007s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20894,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.915544 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:36.927230 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4361,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.927979 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:37.090216 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.162s	user 0.143s	sys 0.016s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":269,"lbm_read_time_us":11271,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33057,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18560,"update_count":2500}
I20260812 06:17:37.090998 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=11.118625
I20260812 06:17:37.124511 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.033s	user 0.024s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13784,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:37.125084 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:37.151674 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.026s	user 0.007s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5910,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:37.152143 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:37.162586 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4046,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.163030 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:37.313577 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.150s	user 0.110s	sys 0.040s 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":690,"lbm_read_time_us":10475,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30884,"lbm_writes_lt_1ms":543,"mutex_wait_us":278,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":2500}
I20260812 06:17:37.314337 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=11.118625
I20260812 06:17:37.349478 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.035s	user 0.027s	sys 0.005s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15388,"lbm_writes_lt_1ms":313,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":1550}
I20260812 06:17:37.350190 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:37.363870 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5244,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:37.364513 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushMRSOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:37.394567 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushMRSOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.030s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":261,"dirs.run_wall_time_us":1329,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1369,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:37.395211 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling LogGCOp(309150624deb497d9f952091e17dcc1a): free 112692367 bytes of WAL
I20260812 06:17:37.395447 14813 log_reader.cc:385] T 309150624deb497d9f952091e17dcc1a: removed 11 log segments from log reader
I20260812 06:17:37.395509 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000003 (ops 12-16)
I20260812 06:17:37.395563 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000004 (ops 17-21)
I20260812 06:17:37.395623 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000005 (ops 22-26)
I20260812 06:17:37.395664 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000006 (ops 27-31)
I20260812 06:17:37.395699 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000007 (ops 32-36)
I20260812 06:17:37.395733 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000008 (ops 37-41)
I20260812 06:17:37.395769 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000009 (ops 42-46)
I20260812 06:17:37.395808 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000010 (ops 47-51)
I20260812 06:17:37.395845 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000011 (ops 52-56)
I20260812 06:17:37.395884 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000012 (ops 57-61)
I20260812 06:17:37.395921 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000013 (ops 62-66)
I20260812 06:17:37.419634 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: LogGCOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.024s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:17:37.420099 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=5.165500
I20260812 06:17:37.440645 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.020s	user 0.018s	sys 0.000s Metrics: {"bytes_written":6769231,"delete_count":0,"lbm_write_time_us":8654,"lbm_writes_lt_1ms":168,"reinsert_count":0,"update_count":825}
I20260812 06:17:37.441126 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling UndoDeltaBlockGCOp(309150624deb497d9f952091e17dcc1a): 447 bytes on disk
I20260812 06:17:37.441524 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: UndoDeltaBlockGCOp(309150624deb497d9f952091e17dcc1a) 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:17:37.441982 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:37.448545 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.006s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1436027,"delete_count":0,"lbm_write_time_us":2067,"lbm_writes_lt_1ms":38,"reinsert_count":0,"update_count":175}
I20260812 06:17:37.449009 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:37.625598 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.176s	user 0.144s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877265,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":666,"lbm_read_time_us":12228,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35799,"lbm_writes_lt_1ms":643,"mutex_wait_us":154,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4736,"thread_start_us":87,"threads_started":1,"update_count":3000}
I20260812 06:17:37.627959 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=14.095187
I20260812 06:17:37.673338 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.045s	user 0.022s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19513,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.674080 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:37.692624 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.018s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6240,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.693145 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:37.847394 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.154s	user 0.114s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":397,"lbm_read_time_us":10585,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27966,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:17:37.848223 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=14.095187
I20260812 06:17:37.907387 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.059s	user 0.035s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25771,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.907846 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:38.065814 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.158s	user 0.110s	sys 0.037s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":401,"lbm_read_time_us":9518,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26192,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:38.066551 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=14.095187
I20260812 06:17:38.121764 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.055s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22058,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:38.122241 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:38.134536 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.012s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4098,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.135167 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:38.341970 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.207s	user 0.142s	sys 0.053s 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":253,"lbm_read_time_us":13212,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30747,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":26496,"update_count":2500}
I20260812 06:17:38.342870 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=14.095187
I20260812 06:17:38.396996 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.054s	user 0.025s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21759,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:38.397536 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:38.409262 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4229,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.409763 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:38.565642 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.156s	user 0.120s	sys 0.036s 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":210,"lbm_read_time_us":10406,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31066,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23808,"update_count":2500}
I20260812 06:17:38.566352 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=10.126437
I20260812 06:17:38.604199 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.038s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16320,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:38.604835 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:38.621766 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6824,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.622434 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:38.760152 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.138s	user 0.092s	sys 0.044s 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":855,"lbm_read_time_us":9698,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25169,"lbm_writes_lt_1ms":443,"mutex_wait_us":317,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":40704,"update_count":2000}
I20260812 06:17:38.761057 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=10.126437
I20260812 06:17:38.804827 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.044s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16629,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:38.805338 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:38.819934 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5876,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.820480 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushMRSOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:38.853470 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushMRSOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":278,"dirs.run_wall_time_us":1280,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2052,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:38.854120 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling LogGCOp(309150624deb497d9f952091e17dcc1a): free 120553387 bytes of WAL
I20260812 06:17:38.854410 14813 log_reader.cc:385] T 309150624deb497d9f952091e17dcc1a: removed 12 log segments from log reader
I20260812 06:17:38.854468 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000014 (ops 67-70)
I20260812 06:17:38.854519 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000015 (ops 71-75)
I20260812 06:17:38.854565 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000016 (ops 76-80)
I20260812 06:17:38.854593 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000017 (ops 81-84)
I20260812 06:17:38.854631 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000018 (ops 85-89)
I20260812 06:17:38.854671 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000019 (ops 90-94)
I20260812 06:17:38.854712 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000020 (ops 95-99)
I20260812 06:17:38.854759 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000021 (ops 100-104)
I20260812 06:17:38.854799 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000022 (ops 105-109)
I20260812 06:17:38.854838 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000023 (ops 110-114)
I20260812 06:17:38.854883 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000024 (ops 115-119)
I20260812 06:17:38.854921 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000025 (ops 120-124)
I20260812 06:17:38.881884 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: LogGCOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.028s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:17:38.882334 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling UndoDeltaBlockGCOp(309150624deb497d9f952091e17dcc1a): 462 bytes on disk
I20260812 06:17:38.882845 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: UndoDeltaBlockGCOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:17:38.883390 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:38.898253 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.015s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4513,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.898716 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:38.910000 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3992,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.910769 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:39.092981 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.182s	user 0.149s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":161,"lbm_read_time_us":13260,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36162,"lbm_writes_lt_1ms":643,"mutex_wait_us":41,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17920,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:17:39.093708 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=14.095187
I20260812 06:17:39.151831 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.058s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22621,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.152302 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:39.164211 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4319,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.164695 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:39.323532 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.159s	user 0.130s	sys 0.027s 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":189,"lbm_read_time_us":12348,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29271,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18176,"update_count":2500}
I20260812 06:17:39.324234 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=12.110812
I20260812 06:17:39.372253 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.048s	user 0.036s	sys 0.008s Metrics: {"bytes_written":14399711,"delete_count":0,"lbm_write_time_us":19592,"lbm_writes_lt_1ms":354,"reinsert_count":0,"update_count":1755}
I20260812 06:17:39.372906 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=1.196750
I20260812 06:17:39.390542 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.017s	user 0.008s	sys 0.000s Metrics: {"bytes_written":2420633,"delete_count":0,"lbm_write_time_us":2584,"lbm_writes_lt_1ms":62,"reinsert_count":0,"update_count":295}
I20260812 06:17:39.391069 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:39.401130 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.010s	user 0.006s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3710,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:39.401598 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:39.586609 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.185s	user 0.115s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1244,"lbm_read_time_us":13801,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31514,"lbm_writes_lt_1ms":543,"mutex_wait_us":83,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19584,"update_count":2500}
I20260812 06:17:39.587451 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=14.095187
I20260812 06:17:39.648854 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.061s	user 0.030s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":26295,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.649415 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:39.661232 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4668,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.662092 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:39.847373 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.185s	user 0.120s	sys 0.063s 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":802,"lbm_read_time_us":14859,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32083,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2500}
I20260812 06:17:39.848162 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=14.095187
I20260812 06:17:39.911904 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.064s	user 0.031s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22633,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.912608 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:39.930279 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6587,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.931036 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:40.127103 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.196s	user 0.103s	sys 0.079s 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":321,"lbm_read_time_us":15593,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":571,"lbm_write_time_us":31544,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:17:40.127777 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=14.095187
I20260812 06:17:40.190649 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.063s	user 0.033s	sys 0.022s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":20908,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:40.191186 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:40.202625 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4506,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.203101 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:40.400446 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.197s	user 0.123s	sys 0.063s 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":266,"lbm_read_time_us":12257,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32765,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:17:40.401252 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=14.095187
I20260812 06:17:40.455291 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.054s	user 0.035s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22517,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:40.455794 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:40.477053 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.021s	user 0.001s	sys 0.018s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4194,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.477696 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushMRSOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:40.514633 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushMRSOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.037s	user 0.030s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":252,"dirs.run_wall_time_us":1332,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1845,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:40.515357 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling LogGCOp(309150624deb497d9f952091e17dcc1a): free 132571525 bytes of WAL
I20260812 06:17:40.515597 14813 log_reader.cc:385] T 309150624deb497d9f952091e17dcc1a: removed 13 log segments from log reader
I20260812 06:17:40.515642 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000026 (ops 125-128)
I20260812 06:17:40.515671 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000027 (ops 129-133)
I20260812 06:17:40.515735 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000028 (ops 134-138)
I20260812 06:17:40.515781 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000029 (ops 139-143)
I20260812 06:17:40.515823 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000030 (ops 144-148)
I20260812 06:17:40.515874 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000031 (ops 149-152)
I20260812 06:17:40.515915 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000032 (ops 153-157)
I20260812 06:17:40.515961 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000033 (ops 158-162)
I20260812 06:17:40.516003 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000034 (ops 163-167)
I20260812 06:17:40.516043 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000035 (ops 168-172)
I20260812 06:17:40.516083 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000036 (ops 173-177)
I20260812 06:17:40.516124 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000037 (ops 178-182)
I20260812 06:17:40.516163 14813 log.cc:1079] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: Deleting log segment in path: /tmp/dist-test-taskRbd1XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450001776-14270-0/minicluster-data/ts-0-root/wals/309150624deb497d9f952091e17dcc1a/wal-000000038 (ops 183-187)
I20260812 06:17:40.544661 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: LogGCOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:40.545975 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling UndoDeltaBlockGCOp(309150624deb497d9f952091e17dcc1a): 493 bytes on disk
I20260812 06:17:40.546676 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: UndoDeltaBlockGCOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:17:40.547292 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=3.181125
I20260812 06:17:40.560863 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4518,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:40.561298 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=2.188937
I20260812 06:17:40.571926 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3940,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:40.572458 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a): perf score=1.000000
I20260812 06:17:40.798789 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: MajorDeltaCompactionOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.226s	user 0.157s	sys 0.068s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979740,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":815,"lbm_read_time_us":15729,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36816,"lbm_writes_lt_1ms":743,"mutex_wait_us":122,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6656,"thread_start_us":102,"threads_started":1,"update_count":3500}
I20260812 06:17:40.799997 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=16.079562
I20260812 06:17:40.811789 14270 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.956s	user 1.863s	sys 0.180s
I20260812 06:17:40.850015 14270 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.038s	user 0.001s	sys 0.000s
I20260812 06:17:40.850670 14270 tablet_server.cc:179] TabletServer@127.13.239.129:0 shutting down...
I20260812 06:17:40.850656 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.050s	user 0.019s	sys 0.031s Metrics: {"bytes_written":17681650,"delete_count":0,"lbm_write_time_us":22245,"lbm_writes_lt_1ms":434,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2155}
I20260812 06:17:40.851284 14921 maintenance_manager.cc:419] P f5d05a91df25494fa4d2f9b398dc6a50: Scheduling FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a): perf score=1.196750
I20260812 06:17:40.862250 14813 maintenance_manager.cc:643] P f5d05a91df25494fa4d2f9b398dc6a50: FlushDeltaMemStoresOp(309150624deb497d9f952091e17dcc1a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3911,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:17:40.862947 14270 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:40.863165 14270 tablet_replica.cc:333] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50: stopping tablet replica
I20260812 06:17:40.863296 14270 raft_consensus.cc:2243] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:40.863478 14270 raft_consensus.cc:2272] T 309150624deb497d9f952091e17dcc1a P f5d05a91df25494fa4d2f9b398dc6a50 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:40.866755 14270 tablet_server.cc:196] TabletServer@127.13.239.129:0 shutdown complete.
I20260812 06:17:40.869453 14270 master.cc:562] Master@127.13.239.190:45431 shutting down...
I20260812 06:17:40.872859 14270 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:40.873034 14270 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:40.873116 14270 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9856d490270a4ceeaf4b9a2010b88bd0: stopping tablet replica
I20260812 06:17:40.885587 14270 master.cc:584] Master@127.13.239.190:45431 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5346 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10967 ms total)

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