[==========] 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:11.125931 15778 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.104.190:38819
I20260812 06:17:11.126814 15778 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:11.127323 15778 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:11.133157 15798 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:11.133225 15778 server_base.cc:1061] running on GCE node
W20260812 06:17:11.133406 15791 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:11.133525 15786 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:11.134027 15778 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:11.134151 15778 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:11.134194 15778 hybrid_clock.cc:648] HybridClock initialized: now 1786515431134191 us; error 0 us; skew 500 ppm
I20260812 06:17:11.135848 15778 webserver.cc:533] Webserver started at http://127.15.104.190:43467/ using document root <none> and password file <none>
I20260812 06:17:11.136363 15778 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:11.136451 15778 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:11.136675 15778 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:11.138363 15778 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/master-0-root/instance:
uuid: "2c3beb62209d4b9da6003af3a2b2acca"
format_stamp: "Formatted at 2026-08-12 06:17:11 on dist-test-slave-j2vl"
I20260812 06:17:11.141669 15778 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:11.143565 15806 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:11.144491 15778 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:11.144636 15778 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/master-0-root
uuid: "2c3beb62209d4b9da6003af3a2b2acca"
format_stamp: "Formatted at 2026-08-12 06:17:11 on dist-test-slave-j2vl"
I20260812 06:17:11.144743 15778 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-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:11.154824 15778 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:11.155354 15778 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:11.155519 15778 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:11.162590 15778 rpc_server.cc:307] RPC server started. Bound to: 127.15.104.190:38819
I20260812 06:17:11.162637 15898 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.104.190:38819 every 8 connection(s)
I20260812 06:17:11.164741 15901 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:11.170001 15901 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca: Bootstrap starting.
I20260812 06:17:11.172228 15901 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:11.173077 15901 log.cc:826] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:11.174667 15901 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca: No bootstrap required, opened a new log
I20260812 06:17:11.177282 15901 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2c3beb62209d4b9da6003af3a2b2acca" member_type: VOTER }
I20260812 06:17:11.177474 15901 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:11.177579 15901 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2c3beb62209d4b9da6003af3a2b2acca, State: Initialized, Role: FOLLOWER
I20260812 06:17:11.178125 15901 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [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: "2c3beb62209d4b9da6003af3a2b2acca" member_type: VOTER }
I20260812 06:17:11.178256 15901 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:11.178354 15901 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:11.178498 15901 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:11.179240 15901 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2c3beb62209d4b9da6003af3a2b2acca" member_type: VOTER }
I20260812 06:17:11.179661 15901 leader_election.cc:304] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [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: 2c3beb62209d4b9da6003af3a2b2acca; no voters: 
I20260812 06:17:11.179991 15901 leader_election.cc:290] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:11.180126 15907 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:11.180388 15907 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [term 1 LEADER]: Becoming Leader. State: Replica: 2c3beb62209d4b9da6003af3a2b2acca, State: Running, Role: LEADER
I20260812 06:17:11.180804 15907 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [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: "2c3beb62209d4b9da6003af3a2b2acca" member_type: VOTER }
I20260812 06:17:11.180939 15901 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:11.182674 15908 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2c3beb62209d4b9da6003af3a2b2acca" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2c3beb62209d4b9da6003af3a2b2acca" member_type: VOTER } }
I20260812 06:17:11.182662 15909 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2c3beb62209d4b9da6003af3a2b2acca. Latest consensus state: current_term: 1 leader_uuid: "2c3beb62209d4b9da6003af3a2b2acca" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2c3beb62209d4b9da6003af3a2b2acca" member_type: VOTER } }
I20260812 06:17:11.182794 15908 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:11.182794 15909 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:11.183152 15932 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:11.183256 15778 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:11.185482 15932 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:11.189857 15932 catalog_manager.cc:1383] Generated new cluster ID: 17c94959f3b94480b2c0f11e77b792b3
I20260812 06:17:11.189921 15932 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:11.209219 15932 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:11.210101 15932 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:11.224854 15932 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca: Generated new TSK 0
I20260812 06:17:11.225590 15932 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:11.248152 15778 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:11.251021 15946 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:11.251102 15941 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:11.251075 15940 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:11.251243 15778 server_base.cc:1061] running on GCE node
I20260812 06:17:11.251515 15778 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:11.251581 15778 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:11.251607 15778 hybrid_clock.cc:648] HybridClock initialized: now 1786515431251606 us; error 0 us; skew 500 ppm
I20260812 06:17:11.252609 15778 webserver.cc:533] Webserver started at http://127.15.104.129:35223/ using document root <none> and password file <none>
I20260812 06:17:11.252795 15778 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:11.252871 15778 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:11.252951 15778 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:11.253414 15778 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/instance:
uuid: "d4f36222195844bb859537bc80766f66"
format_stamp: "Formatted at 2026-08-12 06:17:11 on dist-test-slave-j2vl"
I20260812 06:17:11.254959 15778 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:11.255949 15952 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:11.256196 15778 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:11.256270 15778 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root
uuid: "d4f36222195844bb859537bc80766f66"
format_stamp: "Formatted at 2026-08-12 06:17:11 on dist-test-slave-j2vl"
I20260812 06:17:11.256371 15778 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-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:11.264817 15778 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:11.265288 15778 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:11.265839 15778 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:11.266714 15778 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:11.266767 15778 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:11.266836 15778 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:11.266878 15778 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:11.273911 15778 rpc_server.cc:307] RPC server started. Bound to: 127.15.104.129:40261
I20260812 06:17:11.273964 16056 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.104.129:40261 every 8 connection(s)
I20260812 06:17:11.284013 16058 heartbeater.cc:344] Connected to a master server at 127.15.104.190:38819
I20260812 06:17:11.284278 16058 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:11.284740 16058 heartbeater.cc:507] Master 127.15.104.190:38819 requested a full tablet report, sending...
I20260812 06:17:11.286114 15838 ts_manager.cc:194] Registered new tserver with Master: d4f36222195844bb859537bc80766f66 (127.15.104.129:40261)
I20260812 06:17:11.286989 15778 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012410817s
I20260812 06:17:11.287314 15838 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52960
I20260812 06:17:11.298935 15838 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52972:
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:11.314088 16000 tablet_service.cc:1511] Processing CreateTablet for tablet 802f6ec327af453e87f4448dc8929d81 (DEFAULT_TABLE table=heavy-update-compaction-test [id=339473bab70443ebaf0293e7d7b0ab37]), partition=
I20260812 06:17:11.314555 16000 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 802f6ec327af453e87f4448dc8929d81. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:11.316744 16079 tablet_bootstrap.cc:492] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Bootstrap starting.
I20260812 06:17:11.317974 16079 tablet_bootstrap.cc:654] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:11.319116 16079 tablet_bootstrap.cc:492] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: No bootstrap required, opened a new log
I20260812 06:17:11.319242 16079 ts_tablet_manager.cc:1403] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:11.319656 16079 raft_consensus.cc:359] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d4f36222195844bb859537bc80766f66" member_type: VOTER last_known_addr { host: "127.15.104.129" port: 40261 } }
I20260812 06:17:11.319782 16079 raft_consensus.cc:385] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:11.319850 16079 raft_consensus.cc:740] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d4f36222195844bb859537bc80766f66, State: Initialized, Role: FOLLOWER
I20260812 06:17:11.320027 16079 consensus_queue.cc:260] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66 [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: "d4f36222195844bb859537bc80766f66" member_type: VOTER last_known_addr { host: "127.15.104.129" port: 40261 } }
I20260812 06:17:11.320153 16079 raft_consensus.cc:399] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:11.320201 16079 raft_consensus.cc:493] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:11.320257 16079 raft_consensus.cc:3060] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:11.321132 16079 raft_consensus.cc:515] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d4f36222195844bb859537bc80766f66" member_type: VOTER last_known_addr { host: "127.15.104.129" port: 40261 } }
I20260812 06:17:11.321310 16079 leader_election.cc:304] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66 [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: d4f36222195844bb859537bc80766f66; no voters: 
I20260812 06:17:11.321588 16079 leader_election.cc:290] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:11.321681 16081 raft_consensus.cc:2804] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:11.321867 16081 raft_consensus.cc:697] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66 [term 1 LEADER]: Becoming Leader. State: Replica: d4f36222195844bb859537bc80766f66, State: Running, Role: LEADER
I20260812 06:17:11.321975 16079 ts_tablet_manager.cc:1434] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:11.322067 16081 consensus_queue.cc:237] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66 [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: "d4f36222195844bb859537bc80766f66" member_type: VOTER last_known_addr { host: "127.15.104.129" port: 40261 } }
I20260812 06:17:11.322257 16058 heartbeater.cc:499] Master 127.15.104.190:38819 was elected leader, sending a full tablet report...
I20260812 06:17:11.324677 15838 catalog_manager.cc:5719] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66 reported cstate change: term changed from 0 to 1, leader changed from <none> to d4f36222195844bb859537bc80766f66 (127.15.104.129). New cstate: current_term: 1 leader_uuid: "d4f36222195844bb859537bc80766f66" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d4f36222195844bb859537bc80766f66" member_type: VOTER last_known_addr { host: "127.15.104.129" port: 40261 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:11.388147 15778 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.019s	sys 0.008s
I20260812 06:17:11.525084 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushMRSOp(802f6ec327af453e87f4448dc8929d81): perf score=19.054940
I20260812 06:17:11.702634 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushMRSOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.177s	user 0.134s	sys 0.039s Metrics: {"bytes_written":14235627,"cfile_init":1,"compiler_manager_pool.queue_time_us":220,"delete_count":0,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":971,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46095,"lbm_writes_lt_1ms":804,"mutex_wait_us":150,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":163584,"thread_start_us":133,"threads_started":1,"update_count":1735}
I20260812 06:17:11.703972 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling UndoDeltaBlockGCOp(802f6ec327af453e87f4448dc8929d81): 16411394 bytes on disk
I20260812 06:17:11.704676 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: UndoDeltaBlockGCOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:17:11.705086 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:11.717729 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3774463,"delete_count":0,"lbm_write_time_us":4908,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:17:11.718196 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling LogGCOp(802f6ec327af453e87f4448dc8929d81): free 20743880 bytes of WAL
I20260812 06:17:11.718590 15958 log_reader.cc:385] T 802f6ec327af453e87f4448dc8929d81: removed 2 log segments from log reader
I20260812 06:17:11.718675 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000001 (ops 1-6)
I20260812 06:17:11.718766 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000002 (ops 7-11)
I20260812 06:17:11.724334 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: LogGCOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:11.724690 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=1.196750
I20260812 06:17:11.734385 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":2502679,"delete_count":0,"lbm_write_time_us":3407,"lbm_writes_lt_1ms":64,"reinsert_count":0,"update_count":305}
I20260812 06:17:11.734833 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:11.913023 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.178s	user 0.110s	sys 0.068s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774769,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":644,"lbm_read_time_us":13604,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29338,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":311,"threads_started":5,"update_count":2500}
I20260812 06:17:11.913651 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=10.126437
I20260812 06:17:11.957020 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.043s	user 0.032s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17918,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:11.957679 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:11.968384 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3958,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:11.968936 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:12.088569 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.119s	user 0.109s	sys 0.009s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":183,"lbm_read_time_us":8656,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20962,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:17:12.089110 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=10.126437
I20260812 06:17:12.132210 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.043s	user 0.014s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14114,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:12.132745 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:12.147300 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5401,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.147873 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:12.274472 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.126s	user 0.099s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":178,"lbm_read_time_us":7523,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24896,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:17:12.275146 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=10.126437
I20260812 06:17:12.307813 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.033s	user 0.023s	sys 0.006s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13341,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:12.308341 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:12.412218 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.104s	user 0.079s	sys 0.024s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":775,"lbm_read_time_us":6939,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19550,"lbm_writes_lt_1ms":343,"mutex_wait_us":100,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:17:12.412834 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=10.126437
I20260812 06:17:12.462078 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.049s	user 0.018s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16483,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:12.462594 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:12.476629 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5439,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.477097 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:12.599947 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.123s	user 0.093s	sys 0.027s 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":187,"lbm_read_time_us":7658,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24010,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:12.600423 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=10.126437
I20260812 06:17:12.652719 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.052s	user 0.032s	sys 0.004s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16944,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:12.653159 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:12.664011 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3957,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.664737 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:12.787478 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.123s	user 0.088s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":491,"lbm_read_time_us":9576,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21766,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:17:12.788107 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=10.126437
I20260812 06:17:12.827987 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.040s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14545,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:12.828439 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:12.838672 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3903,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.839293 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushMRSOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:12.868932 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushMRSOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":158,"dirs.run_wall_time_us":1297,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1596,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:12.869889 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling LogGCOp(802f6ec327af453e87f4448dc8929d81): free 108082365 bytes of WAL
I20260812 06:17:12.870150 15958 log_reader.cc:385] T 802f6ec327af453e87f4448dc8929d81: removed 11 log segments from log reader
I20260812 06:17:12.870213 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000003 (ops 12-16)
I20260812 06:17:12.870251 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000004 (ops 17-21)
I20260812 06:17:12.870289 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000005 (ops 22-26)
I20260812 06:17:12.870316 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000006 (ops 27-30)
I20260812 06:17:12.870338 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000007 (ops 31-35)
I20260812 06:17:12.870360 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000008 (ops 36-40)
I20260812 06:17:12.870389 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000009 (ops 41-44)
I20260812 06:17:12.870412 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000010 (ops 45-49)
I20260812 06:17:12.870457 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000011 (ops 50-54)
I20260812 06:17:12.870482 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000012 (ops 55-58)
I20260812 06:17:12.870515 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000013 (ops 59-63)
I20260812 06:17:12.896448 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: LogGCOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:12.896876 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling UndoDeltaBlockGCOp(802f6ec327af453e87f4448dc8929d81): 448 bytes on disk
I20260812 06:17:12.897323 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: UndoDeltaBlockGCOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:17:12.897908 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:12.919808 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.022s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.920258 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:12.929960 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3827,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.930335 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:13.103122 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.173s	user 0.125s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":645,"lbm_read_time_us":11870,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35564,"lbm_writes_lt_1ms":643,"mutex_wait_us":50,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12288,"thread_start_us":92,"threads_started":1,"update_count":3000}
I20260812 06:17:13.103734 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=14.095187
I20260812 06:17:13.161298 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.057s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23706,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.161769 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:13.171633 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3739,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.172225 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:13.317528 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.145s	user 0.115s	sys 0.029s 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":244,"lbm_read_time_us":8432,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29017,"lbm_writes_lt_1ms":543,"mutex_wait_us":90,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:13.318697 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=12.110812
I20260812 06:17:13.352939 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.034s	user 0.016s	sys 0.014s Metrics: {"bytes_written":13538205,"delete_count":0,"lbm_write_time_us":14132,"lbm_writes_lt_1ms":333,"reinsert_count":0,"update_count":1650}
I20260812 06:17:13.353607 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=1.196750
I20260812 06:17:13.376982 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.023s	user 0.002s	sys 0.009s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":4579,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:17:13.377553 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:13.388069 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4038,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.388633 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:13.559379 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.171s	user 0.121s	sys 0.039s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774769,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":181,"lbm_read_time_us":12209,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27777,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:17:13.559948 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=14.095187
I20260812 06:17:13.623021 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.063s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22937,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.623492 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:13.633641 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3931,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.634053 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:13.805959 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.172s	user 0.111s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":476,"lbm_read_time_us":12320,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28169,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":63744,"update_count":2500}
I20260812 06:17:13.806499 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=14.095187
I20260812 06:17:13.862073 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.055s	user 0.028s	sys 0.019s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":17788,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.862630 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:13.872982 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4029,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.873490 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:14.052911 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.179s	user 0.105s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":322,"lbm_read_time_us":12790,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30595,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2500}
I20260812 06:17:14.053558 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=11.118625
I20260812 06:17:14.091648 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.038s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16141,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:14.092377 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:14.122385 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.030s	user 0.012s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5074,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:14.122977 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:14.133657 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4182,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.134217 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:14.309216 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.175s	user 0.123s	sys 0.044s 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":914,"lbm_read_time_us":12829,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27949,"lbm_writes_lt_1ms":543,"mutex_wait_us":282,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2500}
I20260812 06:17:14.309955 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=14.095187
I20260812 06:17:14.357430 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.047s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22104,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:14.358057 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:14.378423 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.020s	user 0.007s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4261,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.379117 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushMRSOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:14.418022 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushMRSOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.039s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":264,"dirs.run_wall_time_us":1471,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1718,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:14.418764 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling LogGCOp(802f6ec327af453e87f4448dc8929d81): free 140885445 bytes of WAL
I20260812 06:17:14.419042 15958 log_reader.cc:385] T 802f6ec327af453e87f4448dc8929d81: removed 14 log segments from log reader
I20260812 06:17:14.419091 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000014 (ops 64-68)
I20260812 06:17:14.419121 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000015 (ops 69-72)
I20260812 06:17:14.419191 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000016 (ops 73-77)
I20260812 06:17:14.419238 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000017 (ops 78-82)
I20260812 06:17:14.419313 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000018 (ops 83-87)
I20260812 06:17:14.419361 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000019 (ops 88-92)
I20260812 06:17:14.419402 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000020 (ops 93-97)
I20260812 06:17:14.419443 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000021 (ops 98-102)
I20260812 06:17:14.419483 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000022 (ops 103-107)
I20260812 06:17:14.419523 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000023 (ops 108-112)
I20260812 06:17:14.419564 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000024 (ops 113-116)
I20260812 06:17:14.419603 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000025 (ops 117-121)
I20260812 06:17:14.419642 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000026 (ops 122-126)
I20260812 06:17:14.419682 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000027 (ops 127-130)
I20260812 06:17:14.448901 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: LogGCOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:14.449396 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling UndoDeltaBlockGCOp(802f6ec327af453e87f4448dc8929d81): 492 bytes on disk
I20260812 06:17:14.449815 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: UndoDeltaBlockGCOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:17:14.450304 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=3.181125
I20260812 06:17:14.465019 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4882122,"delete_count":0,"lbm_write_time_us":5536,"lbm_writes_lt_1ms":122,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":595}
I20260812 06:17:14.465636 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:14.474992 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3323180,"delete_count":0,"lbm_write_time_us":3428,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:17:14.475399 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:14.707584 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.232s	user 0.156s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979734,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1979,"lbm_read_time_us":15882,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39310,"lbm_writes_lt_1ms":743,"mutex_wait_us":1624,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":29312,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:17:14.708238 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=14.095187
I20260812 06:17:14.750808 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.042s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19196,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:14.751458 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:14.764830 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5340,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.765286 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:14.943940 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.178s	user 0.134s	sys 0.045s 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":153,"lbm_read_time_us":12159,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31792,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:14.947719 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=14.095187
I20260812 06:17:15.003854 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.056s	user 0.028s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21544,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.004457 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:15.014973 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4122,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.015408 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:15.182512 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.167s	user 0.105s	sys 0.060s 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":153,"lbm_read_time_us":12995,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29038,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:17:15.183176 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=11.118625
I20260812 06:17:15.242468 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.059s	user 0.030s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":23490,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:17:15.243417 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=4.173312
I20260812 06:17:15.259346 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":5415437,"delete_count":0,"lbm_write_time_us":6264,"lbm_writes_lt_1ms":135,"reinsert_count":0,"update_count":660}
I20260812 06:17:15.259881 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=1.196750
I20260812 06:17:15.267186 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.007s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2379604,"delete_count":0,"lbm_write_time_us":2484,"lbm_writes_lt_1ms":61,"reinsert_count":0,"update_count":290}
I20260812 06:17:15.267617 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:15.431708 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.164s	user 0.098s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774771,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":134,"lbm_read_time_us":12578,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29825,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22016,"update_count":2500}
I20260812 06:17:15.432497 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=11.118625
I20260812 06:17:15.467408 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.035s	user 0.024s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14303,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:15.468086 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:15.505695 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.037s	user 0.018s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6183,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:15.506242 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:15.516695 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4126,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.517113 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:15.704933 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.188s	user 0.124s	sys 0.052s 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":1336,"lbm_read_time_us":12761,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29962,"lbm_writes_lt_1ms":543,"mutex_wait_us":304,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:15.705575 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=14.095187
I20260812 06:17:15.755926 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.050s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21756,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.756415 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:15.771476 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5728,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.772815 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:15.950057 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.177s	user 0.115s	sys 0.048s 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":1144,"lbm_read_time_us":11953,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":571,"lbm_write_time_us":28856,"lbm_writes_lt_1ms":543,"mutex_wait_us":309,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:15.950608 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=14.095187
I20260812 06:17:16.005453 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.055s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20351,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:17:16.005936 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:16.017084 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4062,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.017787 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushMRSOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:16.050633 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushMRSOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.033s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":1459,"drs_written":1,"lbm_read_time_us":93,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2067,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:16.051399 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling LogGCOp(802f6ec327af453e87f4448dc8929d81): free 129320791 bytes of WAL
I20260812 06:17:16.051672 15958 log_reader.cc:385] T 802f6ec327af453e87f4448dc8929d81: removed 13 log segments from log reader
I20260812 06:17:16.051733 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000028 (ops 131-135)
I20260812 06:17:16.051771 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000029 (ops 136-140)
I20260812 06:17:16.051807 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000030 (ops 141-144)
I20260812 06:17:16.051865 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000031 (ops 145-149)
I20260812 06:17:16.051888 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000032 (ops 150-154)
I20260812 06:17:16.051921 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000033 (ops 155-159)
I20260812 06:17:16.051955 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000034 (ops 160-164)
I20260812 06:17:16.052000 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000035 (ops 165-169)
I20260812 06:17:16.052026 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000036 (ops 170-174)
I20260812 06:17:16.052048 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000037 (ops 175-178)
I20260812 06:17:16.052078 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000038 (ops 179-183)
I20260812 06:17:16.052111 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000039 (ops 184-188)
I20260812 06:17:16.052140 15958 log.cc:1079] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/802f6ec327af453e87f4448dc8929d81/wal-000000040 (ops 189-193)
I20260812 06:17:16.081552 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: LogGCOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.030s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:16.082602 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling UndoDeltaBlockGCOp(802f6ec327af453e87f4448dc8929d81): 493 bytes on disk
I20260812 06:17:16.083197 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: UndoDeltaBlockGCOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4}
I20260812 06:17:16.083771 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:16.100760 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.017s	user 0.003s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4404,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.101166 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81): perf score=2.188937
I20260812 06:17:16.111086 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: FlushDeltaMemStoresOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3893,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.111462 16060 maintenance_manager.cc:419] P d4f36222195844bb859537bc80766f66: Scheduling MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81): perf score=1.000000
I20260812 06:17:16.204368 15778 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.816s	user 1.786s	sys 0.166s
I20260812 06:17:16.317970 15778 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.113s	user 0.003s	sys 0.000s
I20260812 06:17:16.318655 15778 tablet_server.cc:179] TabletServer@127.15.104.129:0 shutting down...
I20260812 06:17:16.331045 15958 maintenance_manager.cc:643] P d4f36222195844bb859537bc80766f66: MajorDeltaCompactionOp(802f6ec327af453e87f4448dc8929d81) complete. Timing: real 0.219s	user 0.129s	sys 0.090s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979751,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":688,"lbm_read_time_us":14626,"lbm_reads_lt_1ms":770,"lbm_write_time_us":36966,"lbm_writes_lt_1ms":743,"mutex_wait_us":331,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12288,"thread_start_us":70,"threads_started":1,"update_count":3500}
I20260812 06:17:16.331652 15778 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:16.332058 15778 tablet_replica.cc:333] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66: stopping tablet replica
I20260812 06:17:16.332293 15778 raft_consensus.cc:2243] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:16.332562 15778 raft_consensus.cc:2272] T 802f6ec327af453e87f4448dc8929d81 P d4f36222195844bb859537bc80766f66 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:16.350307 15778 tablet_server.cc:196] TabletServer@127.15.104.129:0 shutdown complete.
I20260812 06:17:16.389581 15778 master.cc:562] Master@127.15.104.190:38819 shutting down...
I20260812 06:17:16.393505 15778 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:16.393666 15778 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:16.393721 15778 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2c3beb62209d4b9da6003af3a2b2acca: stopping tablet replica
I20260812 06:17:16.406075 15778 master.cc:584] Master@127.15.104.190:38819 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5369 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:16.505489 15778 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.104.190:37549
I20260812 06:17:16.505896 15778 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:16.508075 15778 server_base.cc:1061] running on GCE node
W20260812 06:17:16.508051 16119 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:16.508176 16117 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:16.508070 16116 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:16.508541 15778 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:16.508587 15778 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:16.508605 15778 hybrid_clock.cc:648] HybridClock initialized: now 1786515436508605 us; error 0 us; skew 500 ppm
I20260812 06:17:16.509498 15778 webserver.cc:533] Webserver started at http://127.15.104.190:37705/ using document root <none> and password file <none>
I20260812 06:17:16.509668 15778 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:16.509738 15778 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:16.509819 15778 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:16.510229 15778 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/master-0-root/instance:
uuid: "84d7636d9a0249f38000432e72c57576"
format_stamp: "Formatted at 2026-08-12 06:17:16 on dist-test-slave-j2vl"
I20260812 06:17:16.511674 15778 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:16.512542 16125 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:16.512789 15778 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:16.512869 15778 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/master-0-root
uuid: "84d7636d9a0249f38000432e72c57576"
format_stamp: "Formatted at 2026-08-12 06:17:16 on dist-test-slave-j2vl"
I20260812 06:17:16.512926 15778 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-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:16.516937 15778 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:16.517206 15778 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:16.520961 15778 rpc_server.cc:307] RPC server started. Bound to: 127.15.104.190:37549
I20260812 06:17:16.522130 16216 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.104.190:37549 every 8 connection(s)
I20260812 06:17:16.522639 16217 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:16.527813 16217 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576: Bootstrap starting.
I20260812 06:17:16.528599 16217 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:16.529631 16217 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576: No bootstrap required, opened a new log
I20260812 06:17:16.530023 16217 raft_consensus.cc:359] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "84d7636d9a0249f38000432e72c57576" member_type: VOTER }
I20260812 06:17:16.530108 16217 raft_consensus.cc:385] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:16.530169 16217 raft_consensus.cc:740] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 84d7636d9a0249f38000432e72c57576, State: Initialized, Role: FOLLOWER
I20260812 06:17:16.530319 16217 consensus_queue.cc:260] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [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: "84d7636d9a0249f38000432e72c57576" member_type: VOTER }
I20260812 06:17:16.530398 16217 raft_consensus.cc:399] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:16.530422 16217 raft_consensus.cc:493] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:16.530500 16217 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:16.531175 16217 raft_consensus.cc:515] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "84d7636d9a0249f38000432e72c57576" member_type: VOTER }
I20260812 06:17:16.531332 16217 leader_election.cc:304] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [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: 84d7636d9a0249f38000432e72c57576; no voters: 
I20260812 06:17:16.531526 16217 leader_election.cc:290] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:16.531652 16221 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:16.531867 16221 raft_consensus.cc:697] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [term 1 LEADER]: Becoming Leader. State: Replica: 84d7636d9a0249f38000432e72c57576, State: Running, Role: LEADER
I20260812 06:17:16.531945 16217 sys_catalog.cc:565] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:16.532022 16221 consensus_queue.cc:237] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [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: "84d7636d9a0249f38000432e72c57576" member_type: VOTER }
I20260812 06:17:16.532445 16223 sys_catalog.cc:455] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "84d7636d9a0249f38000432e72c57576" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "84d7636d9a0249f38000432e72c57576" member_type: VOTER } }
I20260812 06:17:16.532543 16223 sys_catalog.cc:458] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:16.532648 16224 sys_catalog.cc:455] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 84d7636d9a0249f38000432e72c57576. Latest consensus state: current_term: 1 leader_uuid: "84d7636d9a0249f38000432e72c57576" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "84d7636d9a0249f38000432e72c57576" member_type: VOTER } }
I20260812 06:17:16.532728 16224 sys_catalog.cc:458] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:16.533165 16230 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:16.533895 16230 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:16.534073 15778 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:16.535693 16230 catalog_manager.cc:1383] Generated new cluster ID: 5b24c2dcc2f04e2ebd3ad7b6fb8b4c32
I20260812 06:17:16.535754 16230 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:16.543020 16230 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:16.543521 16230 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:16.550836 16230 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576: Generated new TSK 0
I20260812 06:17:16.550990 16230 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:16.566498 15778 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:16.568763 16251 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:16.568849 16250 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:16.569010 16253 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:16.569044 15778 server_base.cc:1061] running on GCE node
I20260812 06:17:16.569227 15778 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:16.569298 15778 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:16.569361 15778 hybrid_clock.cc:648] HybridClock initialized: now 1786515436569360 us; error 0 us; skew 500 ppm
I20260812 06:17:16.570236 15778 webserver.cc:533] Webserver started at http://127.15.104.129:43677/ using document root <none> and password file <none>
I20260812 06:17:16.570433 15778 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:16.570511 15778 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:16.570591 15778 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:16.570986 15778 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/instance:
uuid: "1c3af896152347e3967fbb24befbbd94"
format_stamp: "Formatted at 2026-08-12 06:17:16 on dist-test-slave-j2vl"
I20260812 06:17:16.572510 15778 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:16.573554 16260 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:16.573776 15778 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:16.573869 15778 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root
uuid: "1c3af896152347e3967fbb24befbbd94"
format_stamp: "Formatted at 2026-08-12 06:17:16 on dist-test-slave-j2vl"
I20260812 06:17:16.573958 15778 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-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:16.587636 15778 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:16.587998 15778 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:16.588292 15778 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:16.588735 15778 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:16.588798 15778 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:16.588850 15778 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:16.588901 15778 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:16.593330 15778 rpc_server.cc:307] RPC server started. Bound to: 127.15.104.129:36943
I20260812 06:17:16.593406 16365 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.104.129:36943 every 8 connection(s)
I20260812 06:17:16.601696 16366 heartbeater.cc:344] Connected to a master server at 127.15.104.190:37549
I20260812 06:17:16.601788 16366 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:16.601979 16366 heartbeater.cc:507] Master 127.15.104.190:37549 requested a full tablet report, sending...
I20260812 06:17:16.602556 16151 ts_manager.cc:194] Registered new tserver with Master: 1c3af896152347e3967fbb24befbbd94 (127.15.104.129:36943)
I20260812 06:17:16.602722 15778 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008889596s
I20260812 06:17:16.603379 16151 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39332
I20260812 06:17:16.609771 16151 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39348:
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:16.617985 16304 tablet_service.cc:1511] Processing CreateTablet for tablet fa66bfe403f944ac83fa814110336567 (DEFAULT_TABLE table=heavy-update-compaction-test [id=6531ad722a32474a9adf05aef12182e5]), partition=
I20260812 06:17:16.618258 16304 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet fa66bfe403f944ac83fa814110336567. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:16.620111 16389 tablet_bootstrap.cc:492] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Bootstrap starting.
I20260812 06:17:16.620983 16389 tablet_bootstrap.cc:654] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:16.622110 16389 tablet_bootstrap.cc:492] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: No bootstrap required, opened a new log
I20260812 06:17:16.622207 16389 ts_tablet_manager.cc:1403] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:16.622629 16389 raft_consensus.cc:359] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c3af896152347e3967fbb24befbbd94" member_type: VOTER last_known_addr { host: "127.15.104.129" port: 36943 } }
I20260812 06:17:16.622717 16389 raft_consensus.cc:385] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:16.622778 16389 raft_consensus.cc:740] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1c3af896152347e3967fbb24befbbd94, State: Initialized, Role: FOLLOWER
I20260812 06:17:16.622943 16389 consensus_queue.cc:260] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94 [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: "1c3af896152347e3967fbb24befbbd94" member_type: VOTER last_known_addr { host: "127.15.104.129" port: 36943 } }
I20260812 06:17:16.623018 16389 raft_consensus.cc:399] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:16.623077 16389 raft_consensus.cc:493] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:16.623134 16389 raft_consensus.cc:3060] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:16.624049 16389 raft_consensus.cc:515] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c3af896152347e3967fbb24befbbd94" member_type: VOTER last_known_addr { host: "127.15.104.129" port: 36943 } }
I20260812 06:17:16.624202 16389 leader_election.cc:304] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94 [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: 1c3af896152347e3967fbb24befbbd94; no voters: 
I20260812 06:17:16.624425 16389 leader_election.cc:290] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:16.624549 16392 raft_consensus.cc:2804] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:16.624791 16392 raft_consensus.cc:697] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94 [term 1 LEADER]: Becoming Leader. State: Replica: 1c3af896152347e3967fbb24befbbd94, State: Running, Role: LEADER
I20260812 06:17:16.624788 16366 heartbeater.cc:499] Master 127.15.104.190:37549 was elected leader, sending a full tablet report...
I20260812 06:17:16.624801 16389 ts_tablet_manager.cc:1434] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:16.624944 16392 consensus_queue.cc:237] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94 [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: "1c3af896152347e3967fbb24befbbd94" member_type: VOTER last_known_addr { host: "127.15.104.129" port: 36943 } }
I20260812 06:17:16.626209 16151 catalog_manager.cc:5719] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94 reported cstate change: term changed from 0 to 1, leader changed from <none> to 1c3af896152347e3967fbb24befbbd94 (127.15.104.129). New cstate: current_term: 1 leader_uuid: "1c3af896152347e3967fbb24befbbd94" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c3af896152347e3967fbb24befbbd94" member_type: VOTER last_known_addr { host: "127.15.104.129" port: 36943 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:16.685259 15778 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.014s	sys 0.007s
I20260812 06:17:16.844292 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushMRSOp(fa66bfe403f944ac83fa814110336567): perf score=20.047128
I20260812 06:17:17.004762 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushMRSOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.160s	user 0.134s	sys 0.020s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":929,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43062,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":20224,"update_count":1500}
I20260812 06:17:17.005578 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling LogGCOp(fa66bfe403f944ac83fa814110336567): free 20743880 bytes of WAL
I20260812 06:17:17.005839 16265 log_reader.cc:385] T fa66bfe403f944ac83fa814110336567: removed 2 log segments from log reader
I20260812 06:17:17.005887 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000001 (ops 1-6)
I20260812 06:17:17.005918 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000002 (ops 7-11)
I20260812 06:17:17.010251 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: LogGCOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.004s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:17:17.010620 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:17.029794 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.019s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.030252 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:17.170070 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.140s	user 0.114s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":587,"lbm_read_time_us":9625,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22822,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":344,"threads_started":5,"update_count":2000}
I20260812 06:17:17.171180 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling UndoDeltaBlockGCOp(fa66bfe403f944ac83fa814110336567): 20513813 bytes on disk
I20260812 06:17:17.171778 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: UndoDeltaBlockGCOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":90,"lbm_reads_lt_1ms":4}
I20260812 06:17:17.172389 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=12.110812
I20260812 06:17:17.213557 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.041s	user 0.021s	sys 0.020s Metrics: {"bytes_written":13866409,"delete_count":0,"lbm_write_time_us":18301,"lbm_writes_lt_1ms":341,"reinsert_count":0,"update_count":1690}
I20260812 06:17:17.214061 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=1.196750
I20260812 06:17:17.224910 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.011s	user 0.002s	sys 0.004s Metrics: {"bytes_written":2543704,"delete_count":0,"lbm_write_time_us":2675,"lbm_writes_lt_1ms":65,"reinsert_count":0,"update_count":310}
I20260812 06:17:17.225417 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:17.381371 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.156s	user 0.093s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713236,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":219,"lbm_read_time_us":9416,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25080,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:17.381880 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=14.095187
I20260812 06:17:17.429116 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.047s	user 0.044s	sys 0.000s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20508,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.429643 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:17.449579 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.020s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5729,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.450165 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:17.633117 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.183s	user 0.119s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":457,"lbm_read_time_us":12197,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30018,"lbm_writes_lt_1ms":543,"mutex_wait_us":251,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":2500}
I20260812 06:17:17.633659 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=14.095187
I20260812 06:17:17.690316 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.056s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20383,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.690806 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:17.702557 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4282,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.703047 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:17.881651 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.178s	user 0.138s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":670,"lbm_read_time_us":9938,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29616,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19840,"update_count":2500}
I20260812 06:17:17.882309 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=14.095187
I20260812 06:17:17.928532 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.046s	user 0.021s	sys 0.021s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21146,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.929035 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:17.943890 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5630,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.944433 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:18.088995 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.144s	user 0.115s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":553,"lbm_read_time_us":11414,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27397,"lbm_writes_lt_1ms":543,"mutex_wait_us":212,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2500}
I20260812 06:17:18.089608 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=10.126437
I20260812 06:17:18.129699 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.040s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16309,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:18.130158 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:18.140661 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4171,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.141120 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:18.268690 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.127s	user 0.095s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":254,"lbm_read_time_us":9016,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23182,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2000}
I20260812 06:17:18.269440 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=10.126437
I20260812 06:17:18.315524 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.046s	user 0.010s	sys 0.021s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14673,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:18.316056 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:18.327167 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3881,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.327627 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushMRSOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:18.360808 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushMRSOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.033s	user 0.027s	sys 0.005s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":1413,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1594,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:18.361455 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling LogGCOp(fa66bfe403f944ac83fa814110336567): free 133024363 bytes of WAL
I20260812 06:17:18.361662 16265 log_reader.cc:385] T fa66bfe403f944ac83fa814110336567: removed 13 log segments from log reader
I20260812 06:17:18.361720 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000003 (ops 12-16)
I20260812 06:17:18.361773 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000004 (ops 17-21)
I20260812 06:17:18.361831 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000005 (ops 22-26)
I20260812 06:17:18.361876 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000006 (ops 27-31)
I20260812 06:17:18.361912 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000007 (ops 32-36)
I20260812 06:17:18.361948 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000008 (ops 37-41)
I20260812 06:17:18.361986 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000009 (ops 42-46)
I20260812 06:17:18.362023 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000010 (ops 47-50)
I20260812 06:17:18.362061 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000011 (ops 51-55)
I20260812 06:17:18.362097 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000012 (ops 56-60)
I20260812 06:17:18.362133 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000013 (ops 61-65)
I20260812 06:17:18.362169 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000014 (ops 66-70)
I20260812 06:17:18.362206 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000015 (ops 71-75)
I20260812 06:17:18.388316 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: LogGCOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:18.388674 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=5.165500
I20260812 06:17:18.403789 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":6482066,"delete_count":0,"lbm_write_time_us":6220,"lbm_writes_lt_1ms":161,"reinsert_count":0,"update_count":790}
I20260812 06:17:18.404183 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling UndoDeltaBlockGCOp(fa66bfe403f944ac83fa814110336567): 482 bytes on disk
I20260812 06:17:18.404562 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: UndoDeltaBlockGCOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:17:18.404958 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:18.420521 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.015s	user 0.007s	sys 0.000s Metrics: {"bytes_written":1723202,"delete_count":0,"lbm_write_time_us":2881,"lbm_writes_lt_1ms":45,"reinsert_count":0,"update_count":210}
I20260812 06:17:18.421139 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:18.598811 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.177s	user 0.136s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":564,"lbm_read_time_us":12492,"lbm_reads_lt_1ms":666,"lbm_write_time_us":34127,"lbm_writes_lt_1ms":643,"mutex_wait_us":3,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15104,"thread_start_us":138,"threads_started":1,"update_count":3000}
I20260812 06:17:18.599463 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=14.095187
I20260812 06:17:18.644538 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.045s	user 0.021s	sys 0.020s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":19754,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.645203 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:18.659780 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.660254 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:18.825237 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.165s	user 0.099s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":413,"lbm_read_time_us":11395,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29564,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:17:18.825958 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=14.095187
I20260812 06:17:18.876585 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.050s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20238,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.877139 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:19.016710 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.139s	user 0.087s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713151,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":860,"lbm_read_time_us":9115,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22445,"lbm_writes_lt_1ms":443,"mutex_wait_us":329,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2000}
I20260812 06:17:19.017447 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=14.095187
I20260812 06:17:19.071590 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.054s	user 0.036s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22783,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:19.072047 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:19.082414 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3966,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.082826 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:19.271785 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.189s	user 0.132s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":145,"lbm_read_time_us":10106,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29437,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":80640,"update_count":2500}
I20260812 06:17:19.272485 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=14.095187
I20260812 06:17:19.325917 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.053s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21930,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:19.326429 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:19.336863 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4093,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.337476 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:19.495311 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.158s	user 0.123s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":464,"lbm_read_time_us":9235,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30733,"lbm_writes_lt_1ms":543,"mutex_wait_us":79,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:17:19.495857 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=11.118625
I20260812 06:17:19.531526 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.036s	user 0.030s	sys 0.003s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15011,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:19.532243 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:19.547344 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5677,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:19.547835 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:19.672605 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.125s	user 0.092s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":127,"lbm_read_time_us":9183,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24493,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:17:19.673414 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=11.118625
I20260812 06:17:19.708773 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.035s	user 0.018s	sys 0.014s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15907,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:17:19.709458 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:19.724607 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5384,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:19.725119 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushMRSOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:19.782586 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushMRSOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.057s	user 0.031s	sys 0.004s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1411,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1625,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:19.783255 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling LogGCOp(fa66bfe403f944ac83fa814110336567): free 116849544 bytes of WAL
I20260812 06:17:19.783540 16265 log_reader.cc:385] T fa66bfe403f944ac83fa814110336567: removed 12 log segments from log reader
I20260812 06:17:19.783603 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000016 (ops 76-80)
I20260812 06:17:19.783643 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000017 (ops 81-84)
I20260812 06:17:19.783676 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000018 (ops 85-89)
I20260812 06:17:19.783699 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000019 (ops 90-94)
I20260812 06:17:19.783726 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000020 (ops 95-99)
I20260812 06:17:19.783753 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000021 (ops 100-104)
I20260812 06:17:19.783788 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000022 (ops 105-108)
I20260812 06:17:19.783821 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000023 (ops 109-113)
I20260812 06:17:19.783859 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000024 (ops 114-118)
I20260812 06:17:19.783881 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000025 (ops 119-122)
I20260812 06:17:19.783902 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000026 (ops 123-127)
I20260812 06:17:19.783934 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000027 (ops 128-132)
I20260812 06:17:19.813141 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: LogGCOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:19.813668 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=6.157687
I20260812 06:17:19.840984 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.027s	user 0.014s	sys 0.008s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":10500,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:19.841566 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling UndoDeltaBlockGCOp(fa66bfe403f944ac83fa814110336567): 472 bytes on disk
I20260812 06:17:19.841964 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: UndoDeltaBlockGCOp(fa66bfe403f944ac83fa814110336567) 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:19.842445 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:19.859776 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6437,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.860495 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:20.044626 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.184s	user 0.112s	sys 0.071s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1070,"lbm_read_time_us":13191,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37368,"lbm_writes_lt_1ms":743,"mutex_wait_us":335,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:17:20.045213 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=14.095187
I20260812 06:17:20.118747 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.073s	user 0.034s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":34468,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.119251 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=6.157687
I20260812 06:17:20.147243 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.028s	user 0.017s	sys 0.009s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11582,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:20.147833 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:20.312022 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.164s	user 0.123s	sys 0.041s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":75,"lbm_read_time_us":12324,"lbm_reads_lt_1ms":668,"lbm_write_time_us":33340,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":40064,"update_count":3000}
I20260812 06:17:20.312932 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=14.095187
I20260812 06:17:20.359042 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.046s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409911,"delete_count":0,"lbm_write_time_us":19913,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.359752 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:20.380056 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.020s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6761,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.380556 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:20.533289 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.153s	user 0.118s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815693,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":303,"lbm_read_time_us":10146,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29045,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:17:20.534020 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=14.095187
I20260812 06:17:20.576725 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.042s	user 0.026s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18530,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.577559 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:20.744362 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.167s	user 0.096s	sys 0.062s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":624,"lbm_read_time_us":11957,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23359,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":77952,"update_count":2000}
I20260812 06:17:20.745030 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=14.095187
I20260812 06:17:20.797652 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.052s	user 0.041s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23047,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.798206 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:20.814397 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.016s	user 0.013s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6301,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.814925 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:21.005623 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.190s	user 0.119s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":603,"lbm_read_time_us":13916,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30028,"lbm_writes_lt_1ms":543,"mutex_wait_us":293,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19200,"update_count":2500}
I20260812 06:17:21.006194 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=14.095187
I20260812 06:17:21.062601 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.056s	user 0.035s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25554,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:21.063185 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:21.079923 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.017s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6317,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.080447 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:21.238674 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.158s	user 0.133s	sys 0.015s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":348,"lbm_read_time_us":11349,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28759,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:17:21.239295 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=14.095187
I20260812 06:17:21.287092 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.048s	user 0.035s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19595,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:21.287562 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:21.299566 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4375,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.300146 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushMRSOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:21.342903 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushMRSOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.042s	user 0.041s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1259,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2124,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:21.343678 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling LogGCOp(fa66bfe403f944ac83fa814110336567): free 136275455 bytes of WAL
I20260812 06:17:21.343966 16265 log_reader.cc:385] T fa66bfe403f944ac83fa814110336567: removed 13 log segments from log reader
I20260812 06:17:21.344033 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000028 (ops 133-137)
I20260812 06:17:21.344075 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000029 (ops 138-142)
I20260812 06:17:21.344112 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000030 (ops 143-147)
I20260812 06:17:21.344141 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000031 (ops 148-152)
I20260812 06:17:21.344167 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000032 (ops 153-156)
I20260812 06:17:21.344194 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000033 (ops 157-161)
I20260812 06:17:21.344228 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000034 (ops 162-166)
I20260812 06:17:21.344259 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000035 (ops 167-171)
I20260812 06:17:21.344290 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000036 (ops 172-176)
I20260812 06:17:21.344321 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000037 (ops 177-181)
I20260812 06:17:21.344347 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000038 (ops 182-186)
I20260812 06:17:21.344373 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000039 (ops 187-191)
I20260812 06:17:21.344411 16265 log.cc:1079] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: Deleting log segment in path: /tmp/dist-test-taskKYvODt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431115692-15778-0/minicluster-data/ts-0-root/wals/fa66bfe403f944ac83fa814110336567/wal-000000040 (ops 192-196)
I20260812 06:17:21.376371 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: LogGCOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:17:21.376813 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=3.181125
I20260812 06:17:21.392863 15778 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.707s	user 1.777s	sys 0.144s
I20260812 06:17:21.403968 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.027s	user 0.009s	sys 0.015s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":7099,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:21.404683 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567): perf score=2.188937
I20260812 06:17:21.413981 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: FlushDeltaMemStoresOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.009s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3702,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:21.414528 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling UndoDeltaBlockGCOp(fa66bfe403f944ac83fa814110336567): 493 bytes on disk
I20260812 06:17:21.414988 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: UndoDeltaBlockGCOp(fa66bfe403f944ac83fa814110336567) 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:21.415711 16368 maintenance_manager.cc:419] P 1c3af896152347e3967fbb24befbbd94: Scheduling MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567): perf score=1.000000
I20260812 06:17:21.499274 15778 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.106s	user 0.002s	sys 0.000s
I20260812 06:17:21.499867 15778 tablet_server.cc:179] TabletServer@127.15.104.129:0 shutting down...
I20260812 06:17:21.594651 16265 maintenance_manager.cc:643] P 1c3af896152347e3967fbb24befbbd94: MajorDeltaCompactionOp(fa66bfe403f944ac83fa814110336567) complete. Timing: real 0.179s	user 0.093s	sys 0.086s Metrics: {"cfile_cache_hit":251,"cfile_cache_hit_bytes":10179090,"cfile_cache_miss":483,"cfile_cache_miss_bytes":22841644,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":665,"lbm_read_time_us":10405,"lbm_reads_lt_1ms":515,"lbm_write_time_us":33287,"lbm_writes_lt_1ms":743,"mutex_wait_us":30,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":72064,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:17:21.595633 15778 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:21.595997 15778 tablet_replica.cc:333] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94: stopping tablet replica
I20260812 06:17:21.596158 15778 raft_consensus.cc:2243] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:21.596338 15778 raft_consensus.cc:2272] T fa66bfe403f944ac83fa814110336567 P 1c3af896152347e3967fbb24befbbd94 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:21.610357 15778 tablet_server.cc:196] TabletServer@127.15.104.129:0 shutdown complete.
I20260812 06:17:21.652457 15778 master.cc:562] Master@127.15.104.190:37549 shutting down...
I20260812 06:17:21.656088 15778 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:21.656334 15778 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:21.656435 15778 tablet_replica.cc:333] T 00000000000000000000000000000000 P 84d7636d9a0249f38000432e72c57576: stopping tablet replica
I20260812 06:17:21.669027 15778 master.cc:584] Master@127.15.104.190:37549 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5257 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10627 ms total)

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