[==========] 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:19:41.088529  4961 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.4.216.126:42905
I20260812 06:19:41.089555  4961 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:19:41.090229  4961 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:41.096297  4975 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:19:41.096275  4972 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:19:41.096606  4978 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:19:41.096623  4961 server_base.cc:1061] running on GCE node
I20260812 06:19:41.097097  4961 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:41.097206  4961 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:19:41.097255  4961 hybrid_clock.cc:648] HybridClock initialized: now 1786515581097253 us; error 0 us; skew 500 ppm
I20260812 06:19:41.098987  4961 webserver.cc:533] Webserver started at http://127.4.216.126:37823/ using document root <none> and password file <none>
I20260812 06:19:41.099524  4961 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:41.099589  4961 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:41.099843  4961 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:41.101433  4961 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/master-0-root/instance:
uuid: "8c11452129ea4a4f84e6a5fc9b2236c0"
format_stamp: "Formatted at 2026-08-12 06:19:41 on dist-test-slave-2p8l"
I20260812 06:19:41.104892  4961 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.002s
I20260812 06:19:41.106956  4984 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:19:41.107928  4961 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:41.108047  4961 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/master-0-root
uuid: "8c11452129ea4a4f84e6a5fc9b2236c0"
format_stamp: "Formatted at 2026-08-12 06:19:41 on dist-test-slave-2p8l"
I20260812 06:19:41.108148  4961 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-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:19:41.127650  4961 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:41.128240  4961 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:19:41.128422  4961 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:41.135954  4961 rpc_server.cc:307] RPC server started. Bound to: 127.4.216.126:42905
I20260812 06:19:41.135967  5080 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.216.126:42905 every 8 connection(s)
I20260812 06:19:41.138191  5082 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:19:41.143666  5082 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0: Bootstrap starting.
I20260812 06:19:41.146029  5082 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:41.146971  5082 log.cc:826] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:41.148612  5082 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0: No bootstrap required, opened a new log
I20260812 06:19:41.151311  5082 raft_consensus.cc:359] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c11452129ea4a4f84e6a5fc9b2236c0" member_type: VOTER }
I20260812 06:19:41.151467  5082 raft_consensus.cc:385] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:41.151594  5082 raft_consensus.cc:740] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8c11452129ea4a4f84e6a5fc9b2236c0, State: Initialized, Role: FOLLOWER
I20260812 06:19:41.152200  5082 consensus_queue.cc:260] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [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: "8c11452129ea4a4f84e6a5fc9b2236c0" member_type: VOTER }
I20260812 06:19:41.152336  5082 raft_consensus.cc:399] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:41.152424  5082 raft_consensus.cc:493] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:41.152549  5082 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:41.153345  5082 raft_consensus.cc:515] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c11452129ea4a4f84e6a5fc9b2236c0" member_type: VOTER }
I20260812 06:19:41.153821  5082 leader_election.cc:304] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [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: 8c11452129ea4a4f84e6a5fc9b2236c0; no voters: 
I20260812 06:19:41.154170  5082 leader_election.cc:290] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:41.154352  5085 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:41.154624  5085 raft_consensus.cc:697] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [term 1 LEADER]: Becoming Leader. State: Replica: 8c11452129ea4a4f84e6a5fc9b2236c0, State: Running, Role: LEADER
I20260812 06:19:41.155077  5085 consensus_queue.cc:237] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [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: "8c11452129ea4a4f84e6a5fc9b2236c0" member_type: VOTER }
I20260812 06:19:41.155229  5082 sys_catalog.cc:565] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:41.156950  5087 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 8c11452129ea4a4f84e6a5fc9b2236c0. Latest consensus state: current_term: 1 leader_uuid: "8c11452129ea4a4f84e6a5fc9b2236c0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c11452129ea4a4f84e6a5fc9b2236c0" member_type: VOTER } }
I20260812 06:19:41.156984  5086 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "8c11452129ea4a4f84e6a5fc9b2236c0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c11452129ea4a4f84e6a5fc9b2236c0" member_type: VOTER } }
I20260812 06:19:41.157059  5087 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:41.157092  5086 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:41.157510  5110 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:41.157796  4961 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:41.160226  5110 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:41.164435  5110 catalog_manager.cc:1383] Generated new cluster ID: 8b99164cfd114b3793cd6df7d21c9840
I20260812 06:19:41.164510  5110 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:41.173300  5110 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:41.174045  5110 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:41.182731  5110 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0: Generated new TSK 0
I20260812 06:19:41.183285  5110 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:41.190676  4961 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:41.193621  5124 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:41.193691  4961 server_base.cc:1061] running on GCE node
W20260812 06:19:41.193768  5123 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:19:41.193868  5130 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:19:41.194116  4961 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:41.194195  4961 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:19:41.194221  4961 hybrid_clock.cc:648] HybridClock initialized: now 1786515581194220 us; error 0 us; skew 500 ppm
I20260812 06:19:41.195117  4961 webserver.cc:533] Webserver started at http://127.4.216.65:38213/ using document root <none> and password file <none>
I20260812 06:19:41.195297  4961 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:41.195370  4961 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:41.195448  4961 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:41.195848  4961 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/instance:
uuid: "81448b38da744a77999e546f57f12cba"
format_stamp: "Formatted at 2026-08-12 06:19:41 on dist-test-slave-2p8l"
I20260812 06:19:41.197355  4961 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:41.198405  5143 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:19:41.198662  4961 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:41.198738  4961 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root
uuid: "81448b38da744a77999e546f57f12cba"
format_stamp: "Formatted at 2026-08-12 06:19:41 on dist-test-slave-2p8l"
I20260812 06:19:41.198822  4961 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-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:19:41.214202  4961 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:41.214653  4961 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:41.215131  4961 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:41.216073  4961 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:41.216125  4961 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:41.216167  4961 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:41.216244  4961 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:41.223178  4961 rpc_server.cc:307] RPC server started. Bound to: 127.4.216.65:34919
I20260812 06:19:41.223225  5257 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.216.65:34919 every 8 connection(s)
I20260812 06:19:41.232751  5259 heartbeater.cc:344] Connected to a master server at 127.4.216.126:42905
I20260812 06:19:41.232981  5259 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:41.233394  5259 heartbeater.cc:507] Master 127.4.216.126:42905 requested a full tablet report, sending...
I20260812 06:19:41.234854  5018 ts_manager.cc:194] Registered new tserver with Master: 81448b38da744a77999e546f57f12cba (127.4.216.65:34919)
I20260812 06:19:41.235191  4961 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01136985s
I20260812 06:19:41.236079  5018 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57904
I20260812 06:19:41.244580  5018 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57912:
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:19:41.258812  5198 tablet_service.cc:1511] Processing CreateTablet for tablet 8e57cbf553bd409d8a8c99fe194aedc5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=515a55f6b3d44ff999913b2b37d41a5c]), partition=
I20260812 06:19:41.259285  5198 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8e57cbf553bd409d8a8c99fe194aedc5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:41.261776  5285 tablet_bootstrap.cc:492] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Bootstrap starting.
I20260812 06:19:41.262980  5285 tablet_bootstrap.cc:654] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:41.264225  5285 tablet_bootstrap.cc:492] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: No bootstrap required, opened a new log
I20260812 06:19:41.264330  5285 ts_tablet_manager.cc:1403] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:41.264832  5285 raft_consensus.cc:359] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "81448b38da744a77999e546f57f12cba" member_type: VOTER last_known_addr { host: "127.4.216.65" port: 34919 } }
I20260812 06:19:41.264952  5285 raft_consensus.cc:385] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:41.264986  5285 raft_consensus.cc:740] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 81448b38da744a77999e546f57f12cba, State: Initialized, Role: FOLLOWER
I20260812 06:19:41.265153  5285 consensus_queue.cc:260] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba [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: "81448b38da744a77999e546f57f12cba" member_type: VOTER last_known_addr { host: "127.4.216.65" port: 34919 } }
I20260812 06:19:41.265259  5285 raft_consensus.cc:399] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:41.265305  5285 raft_consensus.cc:493] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:41.265352  5285 raft_consensus.cc:3060] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:41.266247  5285 raft_consensus.cc:515] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "81448b38da744a77999e546f57f12cba" member_type: VOTER last_known_addr { host: "127.4.216.65" port: 34919 } }
I20260812 06:19:41.266392  5285 leader_election.cc:304] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba [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: 81448b38da744a77999e546f57f12cba; no voters: 
I20260812 06:19:41.266592  5285 leader_election.cc:290] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:41.266738  5287 raft_consensus.cc:2804] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:41.266938  5285 ts_tablet_manager.cc:1434] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.002s
I20260812 06:19:41.267021  5287 raft_consensus.cc:697] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba [term 1 LEADER]: Becoming Leader. State: Replica: 81448b38da744a77999e546f57f12cba, State: Running, Role: LEADER
I20260812 06:19:41.267202  5259 heartbeater.cc:499] Master 127.4.216.126:42905 was elected leader, sending a full tablet report...
I20260812 06:19:41.267202  5287 consensus_queue.cc:237] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba [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: "81448b38da744a77999e546f57f12cba" member_type: VOTER last_known_addr { host: "127.4.216.65" port: 34919 } }
I20260812 06:19:41.270241  5018 catalog_manager.cc:5719] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba reported cstate change: term changed from 0 to 1, leader changed from <none> to 81448b38da744a77999e546f57f12cba (127.4.216.65). New cstate: current_term: 1 leader_uuid: "81448b38da744a77999e546f57f12cba" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "81448b38da744a77999e546f57f12cba" member_type: VOTER last_known_addr { host: "127.4.216.65" port: 34919 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:41.336540  4961 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.022s	sys 0.005s
I20260812 06:19:41.474315  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushMRSOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=19.054940
I20260812 06:19:41.655580  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushMRSOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.181s	user 0.124s	sys 0.045s Metrics: {"bytes_written":13168994,"cfile_init":1,"compiler_manager_pool.queue_time_us":204,"delete_count":0,"dirs.queue_time_us":38,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":813,"drs_written":1,"lbm_read_time_us":157,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42341,"lbm_writes_lt_1ms":778,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":169216,"thread_start_us":136,"threads_started":1,"update_count":1605}
I20260812 06:19:41.657605  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling LogGCOp(8e57cbf553bd409d8a8c99fe194aedc5): free 20743880 bytes of WAL
I20260812 06:19:41.658206  5154 log_reader.cc:385] T 8e57cbf553bd409d8a8c99fe194aedc5: removed 2 log segments from log reader
I20260812 06:19:41.658432  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000001 (ops 1-6)
I20260812 06:19:41.658607  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000002 (ops 7-11)
I20260812 06:19:41.664479  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: LogGCOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.007s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:19:41.664868  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling UndoDeltaBlockGCOp(8e57cbf553bd409d8a8c99fe194aedc5): 16411394 bytes on disk
I20260812 06:19:41.665388  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: UndoDeltaBlockGCOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:19:41.665835  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:41.696867  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.031s	user 0.010s	sys 0.010s Metrics: {"bytes_written":3651384,"delete_count":0,"lbm_write_time_us":5690,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:19:41.697383  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:41.707490  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3861,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:41.708226  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:41.884380  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.176s	user 0.106s	sys 0.069s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774783,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1051,"lbm_read_time_us":14694,"lbm_reads_lt_1ms":569,"lbm_write_time_us":30019,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"thread_start_us":309,"threads_started":5,"update_count":2500}
I20260812 06:19:41.884879  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=10.126437
I20260812 06:19:41.925437  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.040s	user 0.018s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17802,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.925998  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:41.942203  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.016s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6376,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.942660  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:42.069403  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.127s	user 0.104s	sys 0.021s 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":572,"lbm_read_time_us":8520,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25930,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:42.070003  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=10.126437
I20260812 06:19:42.116072  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.046s	user 0.015s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14658,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.116583  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:42.127451  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.011s	user 0.005s	sys 0.004s 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:19:42.128033  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:42.262493  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.134s	user 0.115s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":217,"lbm_read_time_us":11510,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25495,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2000}
I20260812 06:19:42.263173  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=10.126437
I20260812 06:19:42.307744  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.044s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20291,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.308169  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:42.318675  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4137,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.319247  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:42.441440  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.122s	user 0.102s	sys 0.020s 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":234,"lbm_read_time_us":9708,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22532,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:19:42.441990  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=10.126437
I20260812 06:19:42.489934  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.048s	user 0.012s	sys 0.031s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19203,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.490587  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:42.501729  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4423,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.502255  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:42.648132  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.146s	user 0.092s	sys 0.053s 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":890,"lbm_read_time_us":11970,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23634,"lbm_writes_lt_1ms":443,"mutex_wait_us":346,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:42.648859  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=10.126437
I20260812 06:19:42.689734  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.041s	user 0.009s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15967,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.690295  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:42.705493  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5884,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.706024  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:42.830435  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.124s	user 0.087s	sys 0.037s 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":845,"lbm_read_time_us":10749,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23137,"lbm_writes_lt_1ms":443,"mutex_wait_us":326,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2000}
I20260812 06:19:42.831161  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=10.126437
I20260812 06:19:42.867172  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.036s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15714,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.867748  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:42.883605  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.016s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.884127  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushMRSOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:42.911931  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushMRSOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":1522,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1623,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:42.912716  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling LogGCOp(8e57cbf553bd409d8a8c99fe194aedc5): free 112692364 bytes of WAL
I20260812 06:19:42.912937  5154 log_reader.cc:385] T 8e57cbf553bd409d8a8c99fe194aedc5: removed 11 log segments from log reader
I20260812 06:19:42.912982  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000003 (ops 12-16)
I20260812 06:19:42.913012  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000004 (ops 17-21)
I20260812 06:19:42.913084  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000005 (ops 22-26)
I20260812 06:19:42.913112  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000006 (ops 27-31)
I20260812 06:19:42.913153  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000007 (ops 32-36)
I20260812 06:19:42.913182  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000008 (ops 37-41)
I20260812 06:19:42.913216  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000009 (ops 42-46)
I20260812 06:19:42.913254  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000010 (ops 47-51)
I20260812 06:19:42.913290  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000011 (ops 52-56)
I20260812 06:19:42.913327  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000012 (ops 57-61)
I20260812 06:19:42.913365  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000013 (ops 62-66)
I20260812 06:19:42.938959  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: LogGCOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:42.939349  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=3.181125
I20260812 06:19:42.950830  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.011s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4480,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:42.951267  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling UndoDeltaBlockGCOp(8e57cbf553bd409d8a8c99fe194aedc5): 463 bytes on disk
I20260812 06:19:42.951650  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: UndoDeltaBlockGCOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:19:42.952078  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:42.961846  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.010s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3853,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:42.962296  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:43.126567  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.164s	user 0.138s	sys 0.026s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":700,"lbm_read_time_us":12066,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33306,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:19:43.127004  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=14.095187
I20260812 06:19:43.181998  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.055s	user 0.028s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23562,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.182595  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:43.193598  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4490,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.194141  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:43.355266  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.161s	user 0.128s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":326,"lbm_read_time_us":12302,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31619,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:19:43.355931  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=14.095187
I20260812 06:19:43.406625  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.051s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20504,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.407126  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:43.419016  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4150,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.419572  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:43.573637  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.154s	user 0.111s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":207,"lbm_read_time_us":11016,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31542,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":36864,"update_count":2500}
I20260812 06:19:43.574297  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=14.095187
I20260812 06:19:43.631494  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.057s	user 0.021s	sys 0.021s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19638,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.632087  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:43.643919  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4286,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.644650  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:43.813248  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.168s	user 0.119s	sys 0.043s 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":777,"lbm_read_time_us":12622,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31053,"lbm_writes_lt_1ms":543,"mutex_wait_us":77,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:19:43.813827  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=14.095187
I20260812 06:19:43.864571  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.051s	user 0.040s	sys 0.007s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22210,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.865051  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:44.027835  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.163s	user 0.125s	sys 0.031s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1248,"lbm_read_time_us":9434,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27051,"lbm_writes_lt_1ms":443,"mutex_wait_us":383,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:19:44.028484  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=14.095187
I20260812 06:19:44.083227  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.055s	user 0.038s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23107,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:44.083839  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:44.094856  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4014,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.095386  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:44.271368  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.176s	user 0.131s	sys 0.040s 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":194,"lbm_read_time_us":10548,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29571,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:44.272092  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=14.095187
I20260812 06:19:44.321105  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.049s	user 0.020s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19041,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.321604  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:44.333031  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4194,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.333635  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushMRSOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:44.363835  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushMRSOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":198,"dirs.run_wall_time_us":1404,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1466,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:44.364584  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling LogGCOp(8e57cbf553bd409d8a8c99fe194aedc5): free 132571259 bytes of WAL
I20260812 06:19:44.364814  5154 log_reader.cc:385] T 8e57cbf553bd409d8a8c99fe194aedc5: removed 13 log segments from log reader
I20260812 06:19:44.364861  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000014 (ops 67-71)
I20260812 06:19:44.364888  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000015 (ops 72-76)
I20260812 06:19:44.364954  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000016 (ops 77-81)
I20260812 06:19:44.364996  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000017 (ops 82-86)
I20260812 06:19:44.365041  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000018 (ops 87-91)
I20260812 06:19:44.365088  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000019 (ops 92-96)
I20260812 06:19:44.365131  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000020 (ops 97-100)
I20260812 06:19:44.365176  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000021 (ops 101-105)
I20260812 06:19:44.365212  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000022 (ops 106-110)
I20260812 06:19:44.365270  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000023 (ops 111-115)
I20260812 06:19:44.365312  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000024 (ops 116-120)
I20260812 06:19:44.365352  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000025 (ops 121-124)
I20260812 06:19:44.365391  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000026 (ops 125-129)
I20260812 06:19:44.399121  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: LogGCOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.034s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:19:44.399497  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=3.181125
I20260812 06:19:44.413615  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.014s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4305,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:44.414009  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling UndoDeltaBlockGCOp(8e57cbf553bd409d8a8c99fe194aedc5): 482 bytes on disk
I20260812 06:19:44.414712  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: UndoDeltaBlockGCOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:44.415185  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:44.424150  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3529,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:44.424548  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:44.654753  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.230s	user 0.142s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979735,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":62,"lbm_read_time_us":17621,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38993,"lbm_writes_lt_1ms":743,"mutex_wait_us":23,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13568,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:19:44.655617  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=14.095187
I20260812 06:19:44.723205  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.066s	user 0.049s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":29197,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.723858  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:44.747954  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.024s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4486,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.748459  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:44.763129  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5819,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.763616  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:44.975417  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.212s	user 0.127s	sys 0.079s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":742,"lbm_read_time_us":14731,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33581,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:44.976400  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=16.079562
I20260812 06:19:45.057566  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.081s	user 0.038s	sys 0.028s Metrics: {"bytes_written":17722676,"delete_count":0,"lbm_write_time_us":32349,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":433,"reinsert_count":0,"update_count":2160}
I20260812 06:19:45.060003  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=5.165500
I20260812 06:19:45.084923  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.020s	user 0.019s	sys 0.000s Metrics: {"bytes_written":6892309,"delete_count":0,"lbm_write_time_us":8019,"lbm_writes_lt_1ms":171,"reinsert_count":0,"update_count":840}
I20260812 06:19:45.085491  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:45.291539  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.206s	user 0.138s	sys 0.063s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877107,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":657,"lbm_read_time_us":14256,"lbm_reads_lt_1ms":664,"lbm_write_time_us":32531,"lbm_writes_lt_1ms":643,"mutex_wait_us":61,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16128,"update_count":3000}
I20260812 06:19:45.292249  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=18.063937
I20260812 06:19:45.348666  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.056s	user 0.043s	sys 0.008s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":24221,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:45.349339  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:45.522663  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.173s	user 0.113s	sys 0.059s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774573,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":186,"lbm_read_time_us":11152,"lbm_reads_lt_1ms":563,"lbm_write_time_us":30690,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21632,"update_count":2500}
I20260812 06:19:45.523422  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=14.095187
I20260812 06:19:45.582393  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.059s	user 0.038s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22270,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:45.582988  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:45.597275  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5363,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:19:45.597808  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:45.773509  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.176s	user 0.129s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":487,"lbm_read_time_us":12484,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29590,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:45.774276  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=14.095187
I20260812 06:19:45.835638  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.061s	user 0.022s	sys 0.037s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23173,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:45.836225  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:45.846562  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4041,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.846979  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushMRSOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:45.886884  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushMRSOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.040s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":1415,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1928,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:45.887567  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling LogGCOp(8e57cbf553bd409d8a8c99fe194aedc5): free 121006756 bytes of WAL
I20260812 06:19:45.887789  5154 log_reader.cc:385] T 8e57cbf553bd409d8a8c99fe194aedc5: removed 12 log segments from log reader
I20260812 06:19:45.887831  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000027 (ops 130-134)
I20260812 06:19:45.887859  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000028 (ops 135-138)
I20260812 06:19:45.887921  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000029 (ops 139-143)
I20260812 06:19:45.887953  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000030 (ops 144-148)
I20260812 06:19:45.887995  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000031 (ops 149-153)
I20260812 06:19:45.888051  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000032 (ops 154-158)
I20260812 06:19:45.888093  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000033 (ops 159-163)
I20260812 06:19:45.888152  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000034 (ops 164-168)
I20260812 06:19:45.888188  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000035 (ops 169-173)
I20260812 06:19:45.888227  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000036 (ops 174-178)
I20260812 06:19:45.888267  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000037 (ops 179-183)
I20260812 06:19:45.888307  5154 log.cc:1079] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/8e57cbf553bd409d8a8c99fe194aedc5/wal-000000038 (ops 184-188)
I20260812 06:19:45.915833  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: LogGCOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:45.916195  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling UndoDeltaBlockGCOp(8e57cbf553bd409d8a8c99fe194aedc5): 463 bytes on disk
I20260812 06:19:45.916644  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: UndoDeltaBlockGCOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:19:45.917263  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:45.933985  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.017s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4242,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.934412  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=2.188937
I20260812 06:19:45.944694  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3960,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.945147  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:46.176497  4961 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.840s	user 1.815s	sys 0.140s
I20260812 06:19:46.191004  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.246s	user 0.151s	sys 0.083s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":727,"lbm_read_time_us":15113,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41065,"lbm_writes_lt_1ms":743,"mutex_wait_us":330,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:19:46.191677  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=18.063937
I20260812 06:19:46.238481  4961 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.061s	user 0.004s	sys 0.000s
I20260812 06:19:46.239156  4961 tablet_server.cc:179] TabletServer@127.4.216.65:0 shutting down...
I20260812 06:19:46.239838  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: FlushDeltaMemStoresOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.048s	user 0.030s	sys 0.016s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":22014,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:46.240513  5260 maintenance_manager.cc:419] P 81448b38da744a77999e546f57f12cba: Scheduling MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5): perf score=1.000000
I20260812 06:19:46.377678  5154 maintenance_manager.cc:643] P 81448b38da744a77999e546f57f12cba: MajorDeltaCompactionOp(8e57cbf553bd409d8a8c99fe194aedc5) complete. Timing: real 0.137s	user 0.104s	sys 0.032s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":501,"cfile_cache_miss_bytes":20512183,"cfile_init":3,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":505,"lbm_read_time_us":7912,"lbm_reads_lt_1ms":513,"lbm_write_time_us":24651,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:46.378502  4961 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:46.378914  4961 tablet_replica.cc:333] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba: stopping tablet replica
I20260812 06:19:46.379153  4961 raft_consensus.cc:2243] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:46.379385  4961 raft_consensus.cc:2272] T 8e57cbf553bd409d8a8c99fe194aedc5 P 81448b38da744a77999e546f57f12cba [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:46.385056  4961 tablet_server.cc:196] TabletServer@127.4.216.65:0 shutdown complete.
I20260812 06:19:46.425712  4961 master.cc:562] Master@127.4.216.126:42905 shutting down...
I20260812 06:19:46.429816  4961 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:46.430008  4961 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:46.430119  4961 tablet_replica.cc:333] T 00000000000000000000000000000000 P 8c11452129ea4a4f84e6a5fc9b2236c0: stopping tablet replica
I20260812 06:19:46.442384  4961 master.cc:584] Master@127.4.216.126:42905 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5446 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:46.534310  4961 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.4.216.126:37485
I20260812 06:19:46.534718  4961 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:46.537034  5321 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:19:46.537086  5328 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:19:46.537074  4961 server_base.cc:1061] running on GCE node
W20260812 06:19:46.537078  5322 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:46.537451  4961 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:46.537495  4961 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:19:46.537510  4961 hybrid_clock.cc:648] HybridClock initialized: now 1786515586537510 us; error 0 us; skew 500 ppm
I20260812 06:19:46.538451  4961 webserver.cc:533] Webserver started at http://127.4.216.126:41985/ using document root <none> and password file <none>
I20260812 06:19:46.538619  4961 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:46.538677  4961 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:46.538754  4961 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:46.539139  4961 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/master-0-root/instance:
uuid: "d2dad4c60f9e417c87e6dc1e424f4e30"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-2p8l"
I20260812 06:19:46.540616  4961 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:46.541482  5334 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:19:46.541723  4961 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:46.541810  4961 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/master-0-root
uuid: "d2dad4c60f9e417c87e6dc1e424f4e30"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-2p8l"
I20260812 06:19:46.541886  4961 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-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:19:46.562916  4961 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:46.563272  4961 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:46.567304  4961 rpc_server.cc:307] RPC server started. Bound to: 127.4.216.126:37485
I20260812 06:19:46.570930  5433 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:19:46.571165  5432 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.216.126:37485 every 8 connection(s)
I20260812 06:19:46.585117  5433 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30: Bootstrap starting.
I20260812 06:19:46.585891  5433 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:46.586889  5433 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30: No bootstrap required, opened a new log
I20260812 06:19:46.587263  5433 raft_consensus.cc:359] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d2dad4c60f9e417c87e6dc1e424f4e30" member_type: VOTER }
I20260812 06:19:46.587347  5433 raft_consensus.cc:385] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:46.587369  5433 raft_consensus.cc:740] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d2dad4c60f9e417c87e6dc1e424f4e30, State: Initialized, Role: FOLLOWER
I20260812 06:19:46.587481  5433 consensus_queue.cc:260] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [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: "d2dad4c60f9e417c87e6dc1e424f4e30" member_type: VOTER }
I20260812 06:19:46.587538  5433 raft_consensus.cc:399] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:46.587559  5433 raft_consensus.cc:493] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:46.587587  5433 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:46.588253  5433 raft_consensus.cc:515] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d2dad4c60f9e417c87e6dc1e424f4e30" member_type: VOTER }
I20260812 06:19:46.588371  5433 leader_election.cc:304] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [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: d2dad4c60f9e417c87e6dc1e424f4e30; no voters: 
I20260812 06:19:46.588511  5433 leader_election.cc:290] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:46.588703  5437 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:46.588929  5437 raft_consensus.cc:697] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [term 1 LEADER]: Becoming Leader. State: Replica: d2dad4c60f9e417c87e6dc1e424f4e30, State: Running, Role: LEADER
I20260812 06:19:46.589133  5433 sys_catalog.cc:565] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:46.589103  5437 consensus_queue.cc:237] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [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: "d2dad4c60f9e417c87e6dc1e424f4e30" member_type: VOTER }
I20260812 06:19:46.589666  5440 sys_catalog.cc:455] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d2dad4c60f9e417c87e6dc1e424f4e30" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d2dad4c60f9e417c87e6dc1e424f4e30" member_type: VOTER } }
I20260812 06:19:46.589695  5441 sys_catalog.cc:455] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [sys.catalog]: SysCatalogTable state changed. Reason: New leader d2dad4c60f9e417c87e6dc1e424f4e30. Latest consensus state: current_term: 1 leader_uuid: "d2dad4c60f9e417c87e6dc1e424f4e30" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d2dad4c60f9e417c87e6dc1e424f4e30" member_type: VOTER } }
I20260812 06:19:46.589843  5441 sys_catalog.cc:458] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:46.590144  5440 sys_catalog.cc:458] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:46.590437  5449 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:46.591610  5449 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:46.591840  4961 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:46.593569  5449 catalog_manager.cc:1383] Generated new cluster ID: 91c75ed9c96a4c67aa9c298e3d5fe7ec
I20260812 06:19:46.593634  5449 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:46.601277  5449 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:46.601795  5449 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:46.613883  5449 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30: Generated new TSK 0
I20260812 06:19:46.614051  5449 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:46.624191  4961 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:46.626091  5476 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:19:46.626093  5477 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:46.626155  4961 server_base.cc:1061] running on GCE node
W20260812 06:19:46.626119  5481 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:19:46.626488  4961 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:46.626541  4961 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:19:46.626557  4961 hybrid_clock.cc:648] HybridClock initialized: now 1786515586626557 us; error 0 us; skew 500 ppm
I20260812 06:19:46.627378  4961 webserver.cc:533] Webserver started at http://127.4.216.65:42145/ using document root <none> and password file <none>
I20260812 06:19:46.627513  4961 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:46.627573  4961 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:46.627627  4961 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:46.627951  4961 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/instance:
uuid: "f096a3779f8249c483f16bf28f069dc3"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-2p8l"
I20260812 06:19:46.629331  4961 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:46.630234  5489 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:19:46.630473  4961 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:46.630568  4961 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root
uuid: "f096a3779f8249c483f16bf28f069dc3"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-2p8l"
I20260812 06:19:46.630650  4961 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-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:19:46.638511  4961 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:46.638880  4961 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:46.639221  4961 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:46.639740  4961 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:46.639784  4961 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:46.639856  4961 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:46.639889  4961 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:46.644277  4961 rpc_server.cc:307] RPC server started. Bound to: 127.4.216.65:43063
I20260812 06:19:46.644308  5627 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.216.65:43063 every 8 connection(s)
I20260812 06:19:46.652603  5632 heartbeater.cc:344] Connected to a master server at 127.4.216.126:37485
I20260812 06:19:46.652715  5632 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:46.652930  5632 heartbeater.cc:507] Master 127.4.216.126:37485 requested a full tablet report, sending...
I20260812 06:19:46.653574  5364 ts_manager.cc:194] Registered new tserver with Master: f096a3779f8249c483f16bf28f069dc3 (127.4.216.65:43063)
I20260812 06:19:46.654299  5364 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39186
I20260812 06:19:46.654587  4961 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009875873s
I20260812 06:19:46.660879  5364 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39190:
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:19:46.668938  5550 tablet_service.cc:1511] Processing CreateTablet for tablet d1a5eba8f134447092be69abe35e53f8 (DEFAULT_TABLE table=heavy-update-compaction-test [id=83d7e106468b4877a616ff2d94fa5195]), partition=
I20260812 06:19:46.669159  5550 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d1a5eba8f134447092be69abe35e53f8. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:46.670928  5653 tablet_bootstrap.cc:492] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Bootstrap starting.
I20260812 06:19:46.671885  5653 tablet_bootstrap.cc:654] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:46.672838  5653 tablet_bootstrap.cc:492] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: No bootstrap required, opened a new log
I20260812 06:19:46.672910  5653 ts_tablet_manager.cc:1403] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:46.673265  5653 raft_consensus.cc:359] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f096a3779f8249c483f16bf28f069dc3" member_type: VOTER last_known_addr { host: "127.4.216.65" port: 43063 } }
I20260812 06:19:46.673341  5653 raft_consensus.cc:385] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:46.673363  5653 raft_consensus.cc:740] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f096a3779f8249c483f16bf28f069dc3, State: Initialized, Role: FOLLOWER
I20260812 06:19:46.673491  5653 consensus_queue.cc:260] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3 [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: "f096a3779f8249c483f16bf28f069dc3" member_type: VOTER last_known_addr { host: "127.4.216.65" port: 43063 } }
I20260812 06:19:46.673573  5653 raft_consensus.cc:399] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:46.673597  5653 raft_consensus.cc:493] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:46.673626  5653 raft_consensus.cc:3060] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:46.674400  5653 raft_consensus.cc:515] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f096a3779f8249c483f16bf28f069dc3" member_type: VOTER last_known_addr { host: "127.4.216.65" port: 43063 } }
I20260812 06:19:46.674549  5653 leader_election.cc:304] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3 [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: f096a3779f8249c483f16bf28f069dc3; no voters: 
I20260812 06:19:46.674795  5653 leader_election.cc:290] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:46.674882  5656 raft_consensus.cc:2804] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:46.675058  5656 raft_consensus.cc:697] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3 [term 1 LEADER]: Becoming Leader. State: Replica: f096a3779f8249c483f16bf28f069dc3, State: Running, Role: LEADER
I20260812 06:19:46.675143  5653 ts_tablet_manager.cc:1434] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:46.675190  5656 consensus_queue.cc:237] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3 [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: "f096a3779f8249c483f16bf28f069dc3" member_type: VOTER last_known_addr { host: "127.4.216.65" port: 43063 } }
I20260812 06:19:46.675282  5632 heartbeater.cc:499] Master 127.4.216.126:37485 was elected leader, sending a full tablet report...
I20260812 06:19:46.676424  5364 catalog_manager.cc:5719] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3 reported cstate change: term changed from 0 to 1, leader changed from <none> to f096a3779f8249c483f16bf28f069dc3 (127.4.216.65). New cstate: current_term: 1 leader_uuid: "f096a3779f8249c483f16bf28f069dc3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f096a3779f8249c483f16bf28f069dc3" member_type: VOTER last_known_addr { host: "127.4.216.65" port: 43063 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:46.735124  4961 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.012s	sys 0.010s
I20260812 06:19:46.895154  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushMRSOp(d1a5eba8f134447092be69abe35e53f8): perf score=19.054940
I20260812 06:19:47.058889  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushMRSOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.163s	user 0.114s	sys 0.048s Metrics: {"bytes_written":13333096,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":832,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41989,"lbm_writes_lt_1ms":782,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":1920,"update_count":1625}
I20260812 06:19:47.059777  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling LogGCOp(d1a5eba8f134447092be69abe35e53f8): free 20290830 bytes of WAL
I20260812 06:19:47.060047  5498 log_reader.cc:385] T d1a5eba8f134447092be69abe35e53f8: removed 2 log segments from log reader
I20260812 06:19:47.060115  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000001 (ops 1-6)
I20260812 06:19:47.060158  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000002 (ops 7-10)
I20260812 06:19:47.066322  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: LogGCOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.006s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:19:47.066920  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.196750
I20260812 06:19:47.089124  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.019s	user 0.002s	sys 0.006s Metrics: {"bytes_written":3077030,"delete_count":0,"lbm_write_time_us":3440,"lbm_writes_lt_1ms":78,"mutex_wait_us":18,"reinsert_count":0,"update_count":375}
I20260812 06:19:47.089576  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling UndoDeltaBlockGCOp(d1a5eba8f134447092be69abe35e53f8): 16411394 bytes on disk
I20260812 06:19:47.090054  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: UndoDeltaBlockGCOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:47.090502  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:47.104516  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.014s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5631,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.104903  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:47.283548  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.178s	user 0.119s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774785,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":511,"lbm_read_time_us":12010,"lbm_reads_lt_1ms":569,"lbm_write_time_us":30335,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"thread_start_us":316,"threads_started":5,"update_count":2500}
I20260812 06:19:47.284183  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=14.095187
I20260812 06:19:47.339048  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.055s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23251,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.339458  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:47.350446  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4245,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.350976  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:47.502584  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.151s	user 0.108s	sys 0.036s 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":345,"lbm_read_time_us":10901,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30114,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:19:47.503158  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=14.095187
I20260812 06:19:47.553265  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.050s	user 0.025s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18254,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.553740  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:47.565237  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.565739  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:47.739590  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.174s	user 0.117s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":145,"lbm_read_time_us":12101,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32714,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":26624,"update_count":2500}
I20260812 06:19:47.740121  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=14.095187
I20260812 06:19:47.793089  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.053s	user 0.048s	sys 0.000s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22955,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.793536  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:47.804687  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4098,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.805473  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:47.982847  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.177s	user 0.116s	sys 0.052s 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":209,"lbm_read_time_us":12650,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31325,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:19:47.983574  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=14.095187
I20260812 06:19:48.048836  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.065s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23790,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.049325  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:48.060321  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4127,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.061055  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:48.240778  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.180s	user 0.136s	sys 0.040s 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":185,"lbm_read_time_us":12921,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29449,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2500}
I20260812 06:19:48.241364  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=14.095187
I20260812 06:19:48.299572  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.058s	user 0.025s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27082,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.300071  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:48.311590  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4138,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.312165  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushMRSOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:48.341364  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushMRSOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.029s	user 0.012s	sys 0.013s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1476,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1596,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:48.341943  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling LogGCOp(d1a5eba8f134447092be69abe35e53f8): free 121006379 bytes of WAL
I20260812 06:19:48.342180  5498 log_reader.cc:385] T d1a5eba8f134447092be69abe35e53f8: removed 12 log segments from log reader
I20260812 06:19:48.342227  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000003 (ops 11-15)
I20260812 06:19:48.342255  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000004 (ops 16-20)
I20260812 06:19:48.342316  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000005 (ops 21-25)
I20260812 06:19:48.342360  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000006 (ops 26-30)
I20260812 06:19:48.342403  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000007 (ops 31-35)
I20260812 06:19:48.342518  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000008 (ops 36-40)
I20260812 06:19:48.342561  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000009 (ops 41-45)
I20260812 06:19:48.342649  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000010 (ops 46-50)
I20260812 06:19:48.342693  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000011 (ops 51-54)
I20260812 06:19:48.342721  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000012 (ops 55-59)
I20260812 06:19:48.342759  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000013 (ops 60-64)
I20260812 06:19:48.342793  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000014 (ops 65-69)
I20260812 06:19:48.370918  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: LogGCOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.029s	user 0.005s	sys 0.023s Metrics: {}
I20260812 06:19:48.371467  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:48.391671  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.020s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6160,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.392071  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:48.401659  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3814,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.402032  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling UndoDeltaBlockGCOp(d1a5eba8f134447092be69abe35e53f8): 472 bytes on disk
I20260812 06:19:48.402451  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: UndoDeltaBlockGCOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:19:48.402870  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:48.630129  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.227s	user 0.143s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":349,"lbm_read_time_us":16064,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41222,"lbm_writes_lt_1ms":743,"mutex_wait_us":45,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1152,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:19:48.631335  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=18.063937
I20260812 06:19:48.703903  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.072s	user 0.047s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":33016,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:19:48.704483  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=3.181125
I20260812 06:19:48.716949  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4635978,"delete_count":0,"lbm_write_time_us":4886,"lbm_writes_lt_1ms":116,"reinsert_count":0,"update_count":565}
I20260812 06:19:48.717407  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:48.730631  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3569330,"delete_count":0,"lbm_write_time_us":5016,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:19:48.731129  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:48.926189  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.195s	user 0.141s	sys 0.049s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979624,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":911,"lbm_read_time_us":15186,"lbm_reads_lt_1ms":773,"lbm_write_time_us":38015,"lbm_writes_lt_1ms":743,"mutex_wait_us":25,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":3500}
I20260812 06:19:48.926780  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=18.063937
I20260812 06:19:48.989792  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.063s	user 0.023s	sys 0.036s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":29159,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:48.990420  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:49.012858  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.022s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5488,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.013330  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:49.023164  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3899,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.023576  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:49.220194  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.196s	user 0.151s	sys 0.043s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979635,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":596,"lbm_read_time_us":15983,"lbm_reads_lt_1ms":773,"lbm_write_time_us":41032,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":3500}
I20260812 06:19:49.220811  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=15.087375
I20260812 06:19:49.276690  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.056s	user 0.031s	sys 0.022s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":24044,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:49.277582  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:49.292644  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.015s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4563,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:49.293093  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:49.451361  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.158s	user 0.112s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774677,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1180,"lbm_read_time_us":10709,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29051,"lbm_writes_lt_1ms":543,"mutex_wait_us":351,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:49.451936  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=14.095187
I20260812 06:19:49.501508  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.049s	user 0.016s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22922,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.502031  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:49.513794  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4242,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.514575  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:49.693802  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.179s	user 0.137s	sys 0.041s 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":1090,"lbm_read_time_us":13318,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29938,"lbm_writes_lt_1ms":543,"mutex_wait_us":358,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:19:49.695482  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=12.110812
I20260812 06:19:49.739462  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.044s	user 0.032s	sys 0.011s Metrics: {"bytes_written":13620265,"delete_count":0,"lbm_write_time_us":18706,"lbm_writes_lt_1ms":335,"reinsert_count":0,"update_count":1660}
I20260812 06:19:49.740109  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.196750
I20260812 06:19:49.752220  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":4167,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:19:49.752669  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushMRSOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:49.778856  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushMRSOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.026s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":174,"dirs.run_wall_time_us":1401,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1508,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:49.779469  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling LogGCOp(d1a5eba8f134447092be69abe35e53f8): free 124257307 bytes of WAL
I20260812 06:19:49.779685  5498 log_reader.cc:385] T d1a5eba8f134447092be69abe35e53f8: removed 12 log segments from log reader
I20260812 06:19:49.779742  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000015 (ops 70-74)
I20260812 06:19:49.779794  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000016 (ops 75-79)
I20260812 06:19:49.779847  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000017 (ops 80-84)
I20260812 06:19:49.779901  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000018 (ops 85-89)
I20260812 06:19:49.779942  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000019 (ops 90-94)
I20260812 06:19:49.779990  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000020 (ops 95-98)
I20260812 06:19:49.780030  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000021 (ops 99-103)
I20260812 06:19:49.780071  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000022 (ops 104-108)
I20260812 06:19:49.780112  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000023 (ops 109-113)
I20260812 06:19:49.780146  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000024 (ops 114-118)
I20260812 06:19:49.780186  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000025 (ops 119-123)
I20260812 06:19:49.780226  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000026 (ops 124-128)
I20260812 06:19:49.809849  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: LogGCOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:49.810377  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=5.165500
I20260812 06:19:49.826915  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.016s	user 0.007s	sys 0.009s Metrics: {"bytes_written":6892306,"delete_count":0,"lbm_write_time_us":6906,"lbm_writes_lt_1ms":171,"reinsert_count":0,"update_count":840}
I20260812 06:19:49.827364  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling LogGCOp(d1a5eba8f134447092be69abe35e53f8): free 8767145 bytes of WAL
I20260812 06:19:49.827608  5498 log_reader.cc:385] T d1a5eba8f134447092be69abe35e53f8: removed 1 log segments from log reader
I20260812 06:19:49.827651  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000027 (ops 129-133)
I20260812 06:19:49.830147  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: LogGCOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:49.830482  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling UndoDeltaBlockGCOp(d1a5eba8f134447092be69abe35e53f8): 482 bytes on disk
I20260812 06:19:49.830910  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: UndoDeltaBlockGCOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:19:49.831458  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:49.839239  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.008s	user 0.006s	sys 0.001s Metrics: {"bytes_written":1312952,"delete_count":0,"lbm_write_time_us":2151,"lbm_writes_lt_1ms":35,"reinsert_count":0,"update_count":160}
I20260812 06:19:49.839788  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:50.044086  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.204s	user 0.135s	sys 0.059s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877245,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":138,"lbm_read_time_us":14442,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33408,"lbm_writes_lt_1ms":643,"mutex_wait_us":20,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16640,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:19:50.044911  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=18.063937
I20260812 06:19:50.098686  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.053s	user 0.033s	sys 0.020s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":23874,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:50.099226  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:50.112141  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5074,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.112995  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:50.283221  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.170s	user 0.114s	sys 0.056s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":365,"lbm_read_time_us":12677,"lbm_reads_lt_1ms":664,"lbm_write_time_us":35786,"lbm_writes_lt_1ms":643,"mutex_wait_us":33,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":3000}
I20260812 06:19:50.283797  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=14.095187
I20260812 06:19:50.337499  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.054s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23125,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.337971  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:50.349663  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) 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:19:50.350154  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:50.518193  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.168s	user 0.142s	sys 0.019s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":429,"lbm_read_time_us":11164,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31719,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":37120,"update_count":2500}
I20260812 06:19:50.518874  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=14.095187
I20260812 06:19:50.567463  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.048s	user 0.029s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21011,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.567981  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:50.722745  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.154s	user 0.099s	sys 0.045s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":760,"lbm_read_time_us":11314,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25257,"lbm_writes_lt_1ms":443,"mutex_wait_us":280,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2000}
I20260812 06:19:50.723248  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=14.095187
I20260812 06:19:50.783849  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.060s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23535,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.784314  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:50.796418  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4419,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.796908  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:50.964756  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.168s	user 0.136s	sys 0.028s 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":278,"lbm_read_time_us":9997,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26996,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:50.965359  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=14.095187
I20260812 06:19:51.016156  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.051s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22428,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:51.016602  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:51.030503  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5242,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.030932  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:51.194641  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.164s	user 0.128s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":208,"lbm_read_time_us":11985,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28836,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":2500}
I20260812 06:19:51.195571  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=14.095187
I20260812 06:19:51.248996  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.053s	user 0.038s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22946,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:51.249614  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=2.188937
I20260812 06:19:51.261445  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4385,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.261945  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushMRSOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:51.296100  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushMRSOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":309,"dirs.run_wall_time_us":1374,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1600,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:51.296783  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling LogGCOp(d1a5eba8f134447092be69abe35e53f8): free 124257513 bytes of WAL
I20260812 06:19:51.297107  5498 log_reader.cc:385] T d1a5eba8f134447092be69abe35e53f8: removed 12 log segments from log reader
I20260812 06:19:51.297214  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000028 (ops 134-138)
I20260812 06:19:51.297276  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000029 (ops 139-143)
I20260812 06:19:51.297318  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000030 (ops 144-148)
I20260812 06:19:51.297346  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000031 (ops 149-153)
I20260812 06:19:51.297374  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000032 (ops 154-158)
I20260812 06:19:51.297399  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000033 (ops 159-163)
I20260812 06:19:51.297425  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000034 (ops 164-168)
I20260812 06:19:51.297452  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000035 (ops 169-172)
I20260812 06:19:51.297479  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000036 (ops 173-177)
I20260812 06:19:51.297528  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000037 (ops 178-182)
I20260812 06:19:51.297578  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000038 (ops 183-187)
I20260812 06:19:51.297618  5498 log.cc:1079] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: Deleting log segment in path: /tmp/dist-test-taskAJQrtv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581077823-4961-0/minicluster-data/ts-0-root/wals/d1a5eba8f134447092be69abe35e53f8/wal-000000039 (ops 188-192)
I20260812 06:19:51.327797  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: LogGCOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:51.328164  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling UndoDeltaBlockGCOp(d1a5eba8f134447092be69abe35e53f8): 483 bytes on disk
I20260812 06:19:51.328558  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: UndoDeltaBlockGCOp(d1a5eba8f134447092be69abe35e53f8) 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:19:51.329077  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8): perf score=6.157687
I20260812 06:19:51.361513  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: FlushDeltaMemStoresOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.032s	user 0.008s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9266,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:51.362049  5633 maintenance_manager.cc:419] P f096a3779f8249c483f16bf28f069dc3: Scheduling MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8): perf score=1.000000
I20260812 06:19:51.440081  4961 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.705s	user 1.803s	sys 0.146s
I20260812 06:19:51.523373  4961 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.083s	user 0.001s	sys 0.000s
I20260812 06:19:51.523886  4961 tablet_server.cc:179] TabletServer@127.4.216.65:0 shutting down...
I20260812 06:19:51.567467  5498 maintenance_manager.cc:643] P f096a3779f8249c483f16bf28f069dc3: MajorDeltaCompactionOp(d1a5eba8f134447092be69abe35e53f8) complete. Timing: real 0.205s	user 0.150s	sys 0.053s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979632,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":5731,"lbm_read_time_us":17439,"lbm_reads_lt_1ms":761,"lbm_write_time_us":32645,"lbm_writes_lt_1ms":743,"mutex_wait_us":1780,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3840,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:19:51.568234  4961 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:51.568480  4961 tablet_replica.cc:333] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3: stopping tablet replica
I20260812 06:19:51.568624  4961 raft_consensus.cc:2243] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:51.568804  4961 raft_consensus.cc:2272] T d1a5eba8f134447092be69abe35e53f8 P f096a3779f8249c483f16bf28f069dc3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:51.584146  4961 tablet_server.cc:196] TabletServer@127.4.216.65:0 shutdown complete.
I20260812 06:19:51.624751  4961 master.cc:562] Master@127.4.216.126:37485 shutting down...
I20260812 06:19:51.629462  4961 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:51.629689  4961 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:51.629784  4961 tablet_replica.cc:333] T 00000000000000000000000000000000 P d2dad4c60f9e417c87e6dc1e424f4e30: stopping tablet replica
I20260812 06:19:51.642174  4961 master.cc:584] Master@127.4.216.126:37485 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5196 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10644 ms total)

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