[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:18.250710  2488 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.110.62:34659
I20260812 06:18:18.251791  2488 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:18.252421  2488 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:18.258946  2497 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:18.259035  2500 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:18.259119  2488 server_base.cc:1061] running on GCE node
W20260812 06:18:18.259277  2496 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:18.259794  2488 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:18.259884  2488 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:18.259909  2488 hybrid_clock.cc:648] HybridClock initialized: now 1786515498259908 us; error 0 us; skew 500 ppm
I20260812 06:18:18.262349  2488 webserver.cc:533] Webserver started at http://127.2.110.62:37241/ using document root <none> and password file <none>
I20260812 06:18:18.263216  2488 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:18.263306  2488 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:18.263562  2488 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:18.265677  2488 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/master-0-root/instance:
uuid: "358efae4ab864f769546eb0632f6f33a"
format_stamp: "Formatted at 2026-08-12 06:18:18 on dist-test-slave-drl0"
I20260812 06:18:18.269590  2488 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.006s	sys 0.000s
I20260812 06:18:18.272162  2507 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:18.273337  2488 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:18.273471  2488 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/master-0-root
uuid: "358efae4ab864f769546eb0632f6f33a"
format_stamp: "Formatted at 2026-08-12 06:18:18 on dist-test-slave-drl0"
I20260812 06:18:18.273581  2488 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:18.289027  2488 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:18.289654  2488 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:18.289829  2488 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:18.298100  2488 rpc_server.cc:307] RPC server started. Bound to: 127.2.110.62:34659
I20260812 06:18:18.298197  2591 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.110.62:34659 every 8 connection(s)
I20260812 06:18:18.300829  2592 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:18.306142  2592 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a: Bootstrap starting.
I20260812 06:18:18.308665  2592 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:18.309511  2592 log.cc:826] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:18.311822  2592 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a: No bootstrap required, opened a new log
I20260812 06:18:18.315227  2592 raft_consensus.cc:359] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "358efae4ab864f769546eb0632f6f33a" member_type: VOTER }
I20260812 06:18:18.315492  2592 raft_consensus.cc:385] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:18.315591  2592 raft_consensus.cc:740] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 358efae4ab864f769546eb0632f6f33a, State: Initialized, Role: FOLLOWER
I20260812 06:18:18.316205  2592 consensus_queue.cc:260] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [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: "358efae4ab864f769546eb0632f6f33a" member_type: VOTER }
I20260812 06:18:18.316452  2592 raft_consensus.cc:399] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:18.316529  2592 raft_consensus.cc:493] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:18.316663  2592 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:18.317445  2592 raft_consensus.cc:515] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "358efae4ab864f769546eb0632f6f33a" member_type: VOTER }
I20260812 06:18:18.317901  2592 leader_election.cc:304] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [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: 358efae4ab864f769546eb0632f6f33a; no voters: 
I20260812 06:18:18.318246  2592 leader_election.cc:290] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:18.318424  2596 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:18.318698  2596 raft_consensus.cc:697] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [term 1 LEADER]: Becoming Leader. State: Replica: 358efae4ab864f769546eb0632f6f33a, State: Running, Role: LEADER
I20260812 06:18:18.319145  2596 consensus_queue.cc:237] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [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: "358efae4ab864f769546eb0632f6f33a" member_type: VOTER }
I20260812 06:18:18.319293  2592 sys_catalog.cc:565] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:18.321285  2599 sys_catalog.cc:455] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 358efae4ab864f769546eb0632f6f33a. Latest consensus state: current_term: 1 leader_uuid: "358efae4ab864f769546eb0632f6f33a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "358efae4ab864f769546eb0632f6f33a" member_type: VOTER } }
I20260812 06:18:18.321413  2599 sys_catalog.cc:458] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:18.321632  2488 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:18.321779  2620 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:18.321779  2598 sys_catalog.cc:455] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "358efae4ab864f769546eb0632f6f33a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "358efae4ab864f769546eb0632f6f33a" member_type: VOTER } }
I20260812 06:18:18.321921  2598 sys_catalog.cc:458] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:18.324433  2620 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:18.329305  2620 catalog_manager.cc:1383] Generated new cluster ID: 20f52d6b905044da9305b6fed2e66b8c
I20260812 06:18:18.329380  2620 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:18.361480  2620 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:18.362462  2620 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:18.368176  2620 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a: Generated new TSK 0
I20260812 06:18:18.368794  2620 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:18.386502  2488 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:18.390234  2631 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:18.390286  2628 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:18.390249  2627 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:18.391042  2488 server_base.cc:1061] running on GCE node
I20260812 06:18:18.391266  2488 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:18.391328  2488 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:18.391355  2488 hybrid_clock.cc:648] HybridClock initialized: now 1786515498391354 us; error 0 us; skew 500 ppm
I20260812 06:18:18.392297  2488 webserver.cc:533] Webserver started at http://127.2.110.1:39751/ using document root <none> and password file <none>
I20260812 06:18:18.392498  2488 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:18.392575  2488 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:18.392656  2488 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:18.393080  2488 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/instance:
uuid: "b17ed95fcfcf43ef964c67bfb133f520"
format_stamp: "Formatted at 2026-08-12 06:18:18 on dist-test-slave-drl0"
I20260812 06:18:18.394709  2488 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:18.395867  2637 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:18.396131  2488 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:18.396203  2488 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root
uuid: "b17ed95fcfcf43ef964c67bfb133f520"
format_stamp: "Formatted at 2026-08-12 06:18:18 on dist-test-slave-drl0"
I20260812 06:18:18.396292  2488 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:18.402236  2488 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:18.402659  2488 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:18.403236  2488 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:18.404058  2488 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:18.404107  2488 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:18.404174  2488 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:18.404212  2488 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:18.411176  2488 rpc_server.cc:307] RPC server started. Bound to: 127.2.110.1:40081
I20260812 06:18:18.411247  2742 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.110.1:40081 every 8 connection(s)
I20260812 06:18:18.425844  2746 heartbeater.cc:344] Connected to a master server at 127.2.110.62:34659
I20260812 06:18:18.426136  2746 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:18.426601  2746 heartbeater.cc:507] Master 127.2.110.62:34659 requested a full tablet report, sending...
I20260812 06:18:18.428363  2528 ts_manager.cc:194] Registered new tserver with Master: b17ed95fcfcf43ef964c67bfb133f520 (127.2.110.1:40081)
I20260812 06:18:18.428608  2488 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01673936s
I20260812 06:18:18.430074  2528 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:42980
I20260812 06:18:18.438684  2528 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:42984:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:18.455592  2685 tablet_service.cc:1511] Processing CreateTablet for tablet 5888e25d7e9d4ab5befdbe2c1fd98cb5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=5a0a0e32660b4ed285dcc260751db807]), partition=
I20260812 06:18:18.456081  2685 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 5888e25d7e9d4ab5befdbe2c1fd98cb5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:18.458328  2761 tablet_bootstrap.cc:492] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Bootstrap starting.
I20260812 06:18:18.460052  2761 tablet_bootstrap.cc:654] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:18.462023  2761 tablet_bootstrap.cc:492] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: No bootstrap required, opened a new log
I20260812 06:18:18.462205  2761 ts_tablet_manager.cc:1403] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Time spent bootstrapping tablet: real 0.004s	user 0.000s	sys 0.003s
I20260812 06:18:18.462807  2761 raft_consensus.cc:359] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b17ed95fcfcf43ef964c67bfb133f520" member_type: VOTER last_known_addr { host: "127.2.110.1" port: 40081 } }
I20260812 06:18:18.463019  2761 raft_consensus.cc:385] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:18.463114  2761 raft_consensus.cc:740] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b17ed95fcfcf43ef964c67bfb133f520, State: Initialized, Role: FOLLOWER
I20260812 06:18:18.463275  2761 consensus_queue.cc:260] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520 [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: "b17ed95fcfcf43ef964c67bfb133f520" member_type: VOTER last_known_addr { host: "127.2.110.1" port: 40081 } }
I20260812 06:18:18.463395  2761 raft_consensus.cc:399] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:18.463438  2761 raft_consensus.cc:493] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:18.463500  2761 raft_consensus.cc:3060] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:18.464602  2761 raft_consensus.cc:515] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b17ed95fcfcf43ef964c67bfb133f520" member_type: VOTER last_known_addr { host: "127.2.110.1" port: 40081 } }
I20260812 06:18:18.464735  2761 leader_election.cc:304] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520 [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: b17ed95fcfcf43ef964c67bfb133f520; no voters: 
I20260812 06:18:18.465150  2761 leader_election.cc:290] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:18.465256  2763 raft_consensus.cc:2804] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:18.465529  2763 raft_consensus.cc:697] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520 [term 1 LEADER]: Becoming Leader. State: Replica: b17ed95fcfcf43ef964c67bfb133f520, State: Running, Role: LEADER
I20260812 06:18:18.465698  2761 ts_tablet_manager.cc:1434] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:18.465750  2763 consensus_queue.cc:237] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520 [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: "b17ed95fcfcf43ef964c67bfb133f520" member_type: VOTER last_known_addr { host: "127.2.110.1" port: 40081 } }
I20260812 06:18:18.465871  2746 heartbeater.cc:499] Master 127.2.110.62:34659 was elected leader, sending a full tablet report...
I20260812 06:18:18.468811  2528 catalog_manager.cc:5719] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520 reported cstate change: term changed from 0 to 1, leader changed from <none> to b17ed95fcfcf43ef964c67bfb133f520 (127.2.110.1). New cstate: current_term: 1 leader_uuid: "b17ed95fcfcf43ef964c67bfb133f520" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b17ed95fcfcf43ef964c67bfb133f520" member_type: VOTER last_known_addr { host: "127.2.110.1" port: 40081 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:18.549237  2488 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.069s	user 0.026s	sys 0.008s
I20260812 06:18:18.662582  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushMRSOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=15.086190
I20260812 06:18:18.818802  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushMRSOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.156s	user 0.112s	sys 0.039s Metrics: {"bytes_written":8615324,"cfile_init":1,"compiler_manager_pool.queue_time_us":215,"delete_count":0,"dirs.queue_time_us":1178,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":2143,"drs_written":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38092,"lbm_writes_lt_1ms":567,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":73088,"thread_start_us":139,"threads_started":1,"update_count":1050}
I20260812 06:18:18.819921  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling LogGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): free 11976772 bytes of WAL
I20260812 06:18:18.820214  2649 log_reader.cc:385] T 5888e25d7e9d4ab5befdbe2c1fd98cb5: removed 1 log segments from log reader
I20260812 06:18:18.820293  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000001 (ops 1-6)
I20260812 06:18:18.824126  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: LogGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:18.824879  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling UndoDeltaBlockGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): 12308959 bytes on disk
I20260812 06:18:18.825922  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: UndoDeltaBlockGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":134,"lbm_reads_lt_1ms":4}
I20260812 06:18:18.826582  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:18.844731  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.018s	user 0.008s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6390,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:18.845350  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:18.970845  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.125s	user 0.085s	sys 0.032s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528892,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":831,"lbm_read_time_us":7325,"lbm_reads_lt_1ms":360,"lbm_write_time_us":21663,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":440,"threads_started":5,"update_count":1500}
I20260812 06:18:18.971354  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=10.126437
I20260812 06:18:19.019079  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.048s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19480,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:19.019544  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:19.030469  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4538,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.030884  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:19.163326  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.132s	user 0.100s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1188,"lbm_read_time_us":9000,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27467,"lbm_writes_lt_1ms":443,"mutex_wait_us":341,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.164100  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=10.126437
I20260812 06:18:19.212680  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.048s	user 0.031s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16062,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:19.213812  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:19.223896  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.010s	user 0.001s	sys 0.004s Metrics: {"bytes_written":1312955,"delete_count":0,"lbm_write_time_us":1400,"lbm_writes_lt_1ms":35,"reinsert_count":0,"update_count":160}
I20260812 06:18:19.224324  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.196750
I20260812 06:18:19.232218  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.008s	user 0.002s	sys 0.004s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":3083,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:18:19.232642  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:19.391865  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.159s	user 0.106s	sys 0.052s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20631335,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":989,"lbm_read_time_us":13362,"lbm_reads_lt_1ms":473,"lbm_write_time_us":26774,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:18:19.392577  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=10.126437
I20260812 06:18:19.439244  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.047s	user 0.024s	sys 0.020s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":19425,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:19.439855  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:19.451802  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4534,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.452517  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:19.581257  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.129s	user 0.100s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1297,"lbm_read_time_us":10852,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23953,"lbm_writes_lt_1ms":443,"mutex_wait_us":317,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:18:19.581938  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=10.126437
I20260812 06:18:19.626557  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.044s	user 0.033s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18959,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:19.627139  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:19.640376  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.013s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4449,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.641216  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:19.791115  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.150s	user 0.129s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":666,"lbm_read_time_us":9984,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27182,"lbm_writes_lt_1ms":443,"mutex_wait_us":338,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:18:19.791849  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=10.126437
I20260812 06:18:19.843780  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.052s	user 0.019s	sys 0.032s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16910,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:19.844632  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:19.856453  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.012s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4757,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.856980  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:20.009224  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.152s	user 0.096s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":765,"lbm_read_time_us":11309,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23596,"lbm_writes_lt_1ms":443,"mutex_wait_us":288,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2000}
I20260812 06:18:20.009857  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=10.126437
I20260812 06:18:20.058431  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.048s	user 0.015s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18064,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:20.059170  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:20.073791  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6075,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.074273  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:20.212633  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.138s	user 0.110s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1117,"lbm_read_time_us":10067,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27151,"lbm_writes_lt_1ms":443,"mutex_wait_us":566,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:18:20.213260  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=11.118625
I20260812 06:18:20.253352  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.040s	user 0.033s	sys 0.004s Metrics: {"bytes_written":12512611,"delete_count":0,"lbm_write_time_us":17460,"lbm_writes_lt_1ms":308,"reinsert_count":0,"update_count":1525}
I20260812 06:18:20.254293  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:20.276721  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.022s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":5835,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:18:20.277563  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:20.286444  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.009s	user 0.000s	sys 0.004s Metrics: {"bytes_written":1436031,"delete_count":0,"lbm_write_time_us":1610,"lbm_writes_lt_1ms":38,"reinsert_count":0,"update_count":175}
I20260812 06:18:20.286989  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.196750
I20260812 06:18:20.294443  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.007s	user 0.001s	sys 0.005s Metrics: {"bytes_written":2666779,"delete_count":0,"lbm_write_time_us":2709,"lbm_writes_lt_1ms":68,"reinsert_count":0,"update_count":325}
I20260812 06:18:20.294996  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushMRSOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:20.334233  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushMRSOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.039s	user 0.034s	sys 0.001s Metrics: {"bytes_written":1316414,"cfile_init":1,"dirs.queue_time_us":90,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1204,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2412,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:20.335114  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling LogGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): free 129320499 bytes of WAL
I20260812 06:18:20.335330  2649 log_reader.cc:385] T 5888e25d7e9d4ab5befdbe2c1fd98cb5: removed 13 log segments from log reader
I20260812 06:18:20.335371  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000002 (ops 7-11)
I20260812 06:18:20.335435  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000003 (ops 12-16)
I20260812 06:18:20.335480  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000004 (ops 17-21)
I20260812 06:18:20.335546  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000005 (ops 22-26)
I20260812 06:18:20.335584  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000006 (ops 27-30)
I20260812 06:18:20.335628  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000007 (ops 31-35)
I20260812 06:18:20.335668  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000008 (ops 36-40)
I20260812 06:18:20.335708  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000009 (ops 41-45)
I20260812 06:18:20.335750  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000010 (ops 46-50)
I20260812 06:18:20.335789  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000011 (ops 51-54)
I20260812 06:18:20.335830  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000012 (ops 55-59)
I20260812 06:18:20.335870  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000013 (ops 60-64)
I20260812 06:18:20.335919  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000014 (ops 65-69)
I20260812 06:18:20.368166  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: LogGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.033s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:18:20.368657  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=3.181125
I20260812 06:18:20.386891  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.018s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":7474,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:20.387530  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling LogGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): free 12017947 bytes of WAL
I20260812 06:18:20.387725  2649 log_reader.cc:385] T 5888e25d7e9d4ab5befdbe2c1fd98cb5: removed 1 log segments from log reader
I20260812 06:18:20.387768  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000015 (ops 70-74)
I20260812 06:18:20.390520  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: LogGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:20.390810  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling UndoDeltaBlockGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): 493 bytes on disk
I20260812 06:18:20.391215  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: UndoDeltaBlockGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:20.391647  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:20.403514  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4212,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:20.403952  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:20.614322  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.210s	user 0.164s	sys 0.045s Metrics: {"cfile_cache_miss":736,"cfile_cache_miss_bytes":32938914,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":6,"delta_iterators_relevant":6,"dirs.queue_time_us":1023,"lbm_read_time_us":16244,"lbm_reads_lt_1ms":776,"lbm_write_time_us":41401,"lbm_writes_lt_1ms":743,"mutex_wait_us":21,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17536,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:18:20.617581  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=14.095187
I20260812 06:18:20.685209  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.067s	user 0.034s	sys 0.031s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23868,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.685935  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:20.703557  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.017s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6980,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.704051  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:20.897213  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.193s	user 0.112s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":201,"lbm_read_time_us":13220,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31028,"lbm_writes_lt_1ms":543,"mutex_wait_us":84,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:20.897864  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=14.095187
I20260812 06:18:20.962101  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.064s	user 0.039s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":26861,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.962579  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:20.975284  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4100,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.976239  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:21.167084  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.191s	user 0.131s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":366,"lbm_read_time_us":13164,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32281,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:18:21.167797  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=11.118625
I20260812 06:18:21.207221  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.039s	user 0.026s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16492,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:21.207940  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:21.225361  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.017s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4823,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:21.225854  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:21.236757  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4151,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.237353  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:21.414000  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.176s	user 0.140s	sys 0.024s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733833,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":333,"lbm_read_time_us":12493,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31183,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:18:21.414651  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=14.095187
I20260812 06:18:21.468216  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.053s	user 0.030s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18963,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.468758  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:21.481156  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4479,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.481791  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:21.636072  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.154s	user 0.139s	sys 0.007s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1289,"lbm_read_time_us":9230,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30030,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:18:21.636996  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=14.095187
I20260812 06:18:21.691680  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.054s	user 0.019s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19504,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.692306  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:21.706990  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5776,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.707582  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:21.869691  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.162s	user 0.125s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":648,"lbm_read_time_us":9812,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31792,"lbm_writes_lt_1ms":543,"mutex_wait_us":290,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2500}
I20260812 06:18:21.870256  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=14.095187
I20260812 06:18:21.932724  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.062s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23630,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.933193  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:21.946285  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.013s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4140,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.946882  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushMRSOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:21.976797  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushMRSOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.030s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1401,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1962,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:21.977589  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling LogGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): free 121459515 bytes of WAL
I20260812 06:18:21.977849  2649 log_reader.cc:385] T 5888e25d7e9d4ab5befdbe2c1fd98cb5: removed 12 log segments from log reader
I20260812 06:18:21.977897  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000016 (ops 75-79)
I20260812 06:18:21.977944  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000017 (ops 80-84)
I20260812 06:18:21.977984  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000018 (ops 85-89)
I20260812 06:18:21.978027  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000019 (ops 90-94)
I20260812 06:18:21.978071  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000020 (ops 95-99)
I20260812 06:18:21.978111  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000021 (ops 100-104)
I20260812 06:18:21.978150  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000022 (ops 105-109)
I20260812 06:18:21.978188  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000023 (ops 110-114)
I20260812 06:18:21.978226  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000024 (ops 115-119)
I20260812 06:18:21.978266  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000025 (ops 120-124)
I20260812 06:18:21.978303  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000026 (ops 125-129)
I20260812 06:18:21.978341  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000027 (ops 130-134)
I20260812 06:18:22.006093  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: LogGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:22.006500  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling UndoDeltaBlockGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): 493 bytes on disk
I20260812 06:18:22.007342  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: UndoDeltaBlockGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:18:22.008019  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=5.165500
I20260812 06:18:22.025101  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":6687182,"delete_count":0,"lbm_write_time_us":7324,"lbm_writes_lt_1ms":166,"reinsert_count":0,"update_count":815}
I20260812 06:18:22.025529  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:22.035563  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":1518077,"delete_count":0,"lbm_write_time_us":3243,"lbm_writes_lt_1ms":40,"reinsert_count":0,"update_count":185}
I20260812 06:18:22.036124  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:22.264544  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.228s	user 0.171s	sys 0.054s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938721,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":938,"lbm_read_time_us":15668,"lbm_reads_lt_1ms":766,"lbm_write_time_us":47477,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4992,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:18:22.265715  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=15.087375
I20260812 06:18:22.318727  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.053s	user 0.019s	sys 0.022s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":19698,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:22.319352  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:22.337208  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.018s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7366,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.337653  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:22.348251  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3562,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:22.348930  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:22.513298  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.164s	user 0.121s	sys 0.041s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836242,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":220,"lbm_read_time_us":11599,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34406,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3000}
I20260812 06:18:22.513851  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=14.095187
I20260812 06:18:22.561555  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.048s	user 0.029s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20783,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:22.562398  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:22.577982  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5862,"lbm_writes_lt_1ms":103,"mutex_wait_us":2,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.578513  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:22.755092  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.176s	user 0.115s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":709,"lbm_read_time_us":12491,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32159,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:18:22.755788  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=14.095187
I20260812 06:18:22.807646  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.052s	user 0.035s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21165,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:22.808261  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:22.976486  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.168s	user 0.120s	sys 0.041s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631193,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":321,"lbm_read_time_us":12533,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27462,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2000}
I20260812 06:18:22.977149  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=14.095187
I20260812 06:18:23.035596  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.058s	user 0.035s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22283,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.036326  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:23.049185  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4686,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.049697  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:23.237219  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.187s	user 0.137s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1140,"lbm_read_time_us":11272,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30065,"lbm_writes_lt_1ms":543,"mutex_wait_us":279,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:18:23.237903  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=14.095187
I20260812 06:18:23.300137  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.062s	user 0.029s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26612,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.300717  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:23.313886  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5075,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.314388  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:23.495010  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.180s	user 0.130s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":246,"lbm_read_time_us":11593,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34429,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:23.495662  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=14.095187
I20260812 06:18:23.546376  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.051s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21067,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.547243  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:23.564014  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6414,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.564745  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushMRSOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:23.595800  2488 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.046s	user 1.834s	sys 0.127s
I20260812 06:18:23.599077  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushMRSOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.034s	user 0.032s	sys 0.002s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":276,"dirs.run_wall_time_us":1553,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1760,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:23.600065  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling LogGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): free 136728467 bytes of WAL
I20260812 06:18:23.600394  2649 log_reader.cc:385] T 5888e25d7e9d4ab5befdbe2c1fd98cb5: removed 13 log segments from log reader
I20260812 06:18:23.600577  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000028 (ops 135-139)
I20260812 06:18:23.600698  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000029 (ops 140-144)
I20260812 06:18:23.600745  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000030 (ops 145-149)
I20260812 06:18:23.600802  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000031 (ops 150-154)
I20260812 06:18:23.600840  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000032 (ops 155-159)
I20260812 06:18:23.600880  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000033 (ops 160-164)
I20260812 06:18:23.600917  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000034 (ops 165-169)
I20260812 06:18:23.600972  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000035 (ops 170-174)
I20260812 06:18:23.601011  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000036 (ops 175-179)
I20260812 06:18:23.601050  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000037 (ops 180-184)
I20260812 06:18:23.601087  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000038 (ops 185-189)
I20260812 06:18:23.601123  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000039 (ops 190-194)
I20260812 06:18:23.601161  2649 log.cc:1079] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/5888e25d7e9d4ab5befdbe2c1fd98cb5/wal-000000040 (ops 195-199)
I20260812 06:18:23.628216  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: LogGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:23.628749  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling UndoDeltaBlockGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): 492 bytes on disk
I20260812 06:18:23.629209  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: UndoDeltaBlockGCOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:23.629745  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=2.188937
I20260812 06:18:23.641113  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: FlushDeltaMemStoresOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4412,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.641546  2747 maintenance_manager.cc:419] P b17ed95fcfcf43ef964c67bfb133f520: Scheduling MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5): perf score=1.000000
I20260812 06:18:23.649236  2488 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.053s	user 0.002s	sys 0.000s
I20260812 06:18:23.649884  2488 tablet_server.cc:179] TabletServer@127.2.110.1:0 shutting down...
I20260812 06:18:23.775377  2649 maintenance_manager.cc:643] P b17ed95fcfcf43ef964c67bfb133f520: MajorDeltaCompactionOp(5888e25d7e9d4ab5befdbe2c1fd98cb5) complete. Timing: real 0.134s	user 0.115s	sys 0.016s Metrics: {"cfile_cache_hit":532,"cfile_cache_hit_bytes":24733722,"cfile_cache_miss":101,"cfile_cache_miss_bytes":4102531,"cfile_init":3,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":3138,"lbm_read_time_us":2436,"lbm_reads_lt_1ms":113,"lbm_write_time_us":31717,"lbm_writes_lt_1ms":643,"mutex_wait_us":2448,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13696,"thread_start_us":88,"threads_started":1,"update_count":3000}
I20260812 06:18:23.776288  2488 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:23.776835  2488 tablet_replica.cc:333] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520: stopping tablet replica
I20260812 06:18:23.777454  2488 raft_consensus.cc:2243] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:23.778034  2488 raft_consensus.cc:2272] T 5888e25d7e9d4ab5befdbe2c1fd98cb5 P b17ed95fcfcf43ef964c67bfb133f520 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:23.793937  2488 tablet_server.cc:196] TabletServer@127.2.110.1:0 shutdown complete.
I20260812 06:18:23.822821  2488 master.cc:562] Master@127.2.110.62:34659 shutting down...
I20260812 06:18:23.827068  2488 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:23.827227  2488 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:23.827284  2488 tablet_replica.cc:333] T 00000000000000000000000000000000 P 358efae4ab864f769546eb0632f6f33a: stopping tablet replica
I20260812 06:18:23.840360  2488 master.cc:584] Master@127.2.110.62:34659 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5683 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:23.932643  2488 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.110.62:36051
I20260812 06:18:23.933009  2488 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:23.935439  2488 server_base.cc:1061] running on GCE node
W20260812 06:18:23.935467  2795 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:23.935492  2798 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:23.935702  2802 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:23.935916  2488 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:23.935961  2488 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:23.935976  2488 hybrid_clock.cc:648] HybridClock initialized: now 1786515503935976 us; error 0 us; skew 500 ppm
I20260812 06:18:23.937196  2488 webserver.cc:533] Webserver started at http://127.2.110.62:39327/ using document root <none> and password file <none>
I20260812 06:18:23.937403  2488 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:23.937459  2488 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:23.937523  2488 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:23.937966  2488 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/master-0-root/instance:
uuid: "4637955f8c54429d878b40807c3fdab0"
format_stamp: "Formatted at 2026-08-12 06:18:23 on dist-test-slave-drl0"
I20260812 06:18:23.939966  2488 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:23.941637  2809 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:23.942045  2488 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:23.942118  2488 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/master-0-root
uuid: "4637955f8c54429d878b40807c3fdab0"
format_stamp: "Formatted at 2026-08-12 06:18:23 on dist-test-slave-drl0"
I20260812 06:18:23.942184  2488 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:23.986686  2488 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:23.987180  2488 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:23.991490  2488 rpc_server.cc:307] RPC server started. Bound to: 127.2.110.62:36051
I20260812 06:18:24.000943  2886 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.110.62:36051 every 8 connection(s)
I20260812 06:18:24.001255  2887 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:24.010627  2887 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0: Bootstrap starting.
I20260812 06:18:24.011584  2887 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:24.012658  2887 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0: No bootstrap required, opened a new log
I20260812 06:18:24.013036  2887 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4637955f8c54429d878b40807c3fdab0" member_type: VOTER }
I20260812 06:18:24.013125  2887 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:24.013149  2887 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4637955f8c54429d878b40807c3fdab0, State: Initialized, Role: FOLLOWER
I20260812 06:18:24.013312  2887 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [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: "4637955f8c54429d878b40807c3fdab0" member_type: VOTER }
I20260812 06:18:24.013408  2887 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:24.013437  2887 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:24.013468  2887 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:24.014106  2887 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4637955f8c54429d878b40807c3fdab0" member_type: VOTER }
I20260812 06:18:24.014218  2887 leader_election.cc:304] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [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: 4637955f8c54429d878b40807c3fdab0; no voters: 
I20260812 06:18:24.014422  2887 leader_election.cc:290] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:24.014503  2894 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:24.014673  2894 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [term 1 LEADER]: Becoming Leader. State: Replica: 4637955f8c54429d878b40807c3fdab0, State: Running, Role: LEADER
I20260812 06:18:24.014803  2894 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [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: "4637955f8c54429d878b40807c3fdab0" member_type: VOTER }
I20260812 06:18:24.014959  2887 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:24.015262  2895 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4637955f8c54429d878b40807c3fdab0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4637955f8c54429d878b40807c3fdab0" member_type: VOTER } }
I20260812 06:18:24.015316  2897 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4637955f8c54429d878b40807c3fdab0. Latest consensus state: current_term: 1 leader_uuid: "4637955f8c54429d878b40807c3fdab0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4637955f8c54429d878b40807c3fdab0" member_type: VOTER } }
I20260812 06:18:24.015430  2895 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:24.015451  2897 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:24.016039  2903 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:24.016757  2903 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:24.017199  2488 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:24.018704  2903 catalog_manager.cc:1383] Generated new cluster ID: 496782f7eda144bca8a1018c20e07a5f
I20260812 06:18:24.018766  2903 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:24.033746  2903 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:24.034392  2903 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:24.041348  2903 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0: Generated new TSK 0
I20260812 06:18:24.041628  2903 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:24.049791  2488 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:24.052034  2924 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:24.052028  2921 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:24.052057  2488 server_base.cc:1061] running on GCE node
W20260812 06:18:24.052027  2922 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:24.052374  2488 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:24.052425  2488 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:24.052441  2488 hybrid_clock.cc:648] HybridClock initialized: now 1786515504052441 us; error 0 us; skew 500 ppm
I20260812 06:18:24.053375  2488 webserver.cc:533] Webserver started at http://127.2.110.1:44935/ using document root <none> and password file <none>
I20260812 06:18:24.053516  2488 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:24.053560  2488 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:24.053612  2488 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:24.053959  2488 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/instance:
uuid: "12258b8498104899bc1b4a7c9aa76fb1"
format_stamp: "Formatted at 2026-08-12 06:18:24 on dist-test-slave-drl0"
I20260812 06:18:24.055568  2488 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:24.056586  2930 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:24.056898  2488 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:24.056965  2488 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root
uuid: "12258b8498104899bc1b4a7c9aa76fb1"
format_stamp: "Formatted at 2026-08-12 06:18:24 on dist-test-slave-drl0"
I20260812 06:18:24.057019  2488 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:24.069394  2488 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:24.069679  2488 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:24.069921  2488 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:24.070389  2488 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:24.070426  2488 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:24.070484  2488 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:24.070525  2488 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:24.074918  2488 rpc_server.cc:307] RPC server started. Bound to: 127.2.110.1:43355
I20260812 06:18:24.074992  3036 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.110.1:43355 every 8 connection(s)
I20260812 06:18:24.083671  3037 heartbeater.cc:344] Connected to a master server at 127.2.110.62:36051
I20260812 06:18:24.083825  3037 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:24.084080  3037 heartbeater.cc:507] Master 127.2.110.62:36051 requested a full tablet report, sending...
I20260812 06:18:24.085036  2837 ts_manager.cc:194] Registered new tserver with Master: 12258b8498104899bc1b4a7c9aa76fb1 (127.2.110.1:43355)
I20260812 06:18:24.085628  2488 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010221041s
I20260812 06:18:24.085858  2837 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44962
I20260812 06:18:24.093654  2837 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44978:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:24.103127  2974 tablet_service.cc:1511] Processing CreateTablet for tablet d976d8846d21441bb7cd193eeabd79df (DEFAULT_TABLE table=heavy-update-compaction-test [id=71becc2c5795449490861645036431d7]), partition=
I20260812 06:18:24.103497  2974 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d976d8846d21441bb7cd193eeabd79df. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:24.105662  3054 tablet_bootstrap.cc:492] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Bootstrap starting.
I20260812 06:18:24.106663  3054 tablet_bootstrap.cc:654] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:24.108359  3054 tablet_bootstrap.cc:492] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: No bootstrap required, opened a new log
I20260812 06:18:24.108439  3054 ts_tablet_manager.cc:1403] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:24.108904  3054 raft_consensus.cc:359] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "12258b8498104899bc1b4a7c9aa76fb1" member_type: VOTER last_known_addr { host: "127.2.110.1" port: 43355 } }
I20260812 06:18:24.109054  3054 raft_consensus.cc:385] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:24.109107  3054 raft_consensus.cc:740] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 12258b8498104899bc1b4a7c9aa76fb1, State: Initialized, Role: FOLLOWER
I20260812 06:18:24.109269  3054 consensus_queue.cc:260] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1 [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: "12258b8498104899bc1b4a7c9aa76fb1" member_type: VOTER last_known_addr { host: "127.2.110.1" port: 43355 } }
I20260812 06:18:24.109376  3054 raft_consensus.cc:399] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:24.109426  3054 raft_consensus.cc:493] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:24.109488  3054 raft_consensus.cc:3060] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:24.110293  3054 raft_consensus.cc:515] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "12258b8498104899bc1b4a7c9aa76fb1" member_type: VOTER last_known_addr { host: "127.2.110.1" port: 43355 } }
I20260812 06:18:24.110409  3054 leader_election.cc:304] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1 [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: 12258b8498104899bc1b4a7c9aa76fb1; no voters: 
I20260812 06:18:24.110553  3054 leader_election.cc:290] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:24.110723  3057 raft_consensus.cc:2804] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:24.110906  3054 ts_tablet_manager.cc:1434] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:24.110952  3037 heartbeater.cc:499] Master 127.2.110.62:36051 was elected leader, sending a full tablet report...
I20260812 06:18:24.110965  3057 raft_consensus.cc:697] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1 [term 1 LEADER]: Becoming Leader. State: Replica: 12258b8498104899bc1b4a7c9aa76fb1, State: Running, Role: LEADER
I20260812 06:18:24.111363  3057 consensus_queue.cc:237] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1 [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: "12258b8498104899bc1b4a7c9aa76fb1" member_type: VOTER last_known_addr { host: "127.2.110.1" port: 43355 } }
I20260812 06:18:24.112854  2837 catalog_manager.cc:5719] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1 reported cstate change: term changed from 0 to 1, leader changed from <none> to 12258b8498104899bc1b4a7c9aa76fb1 (127.2.110.1). New cstate: current_term: 1 leader_uuid: "12258b8498104899bc1b4a7c9aa76fb1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "12258b8498104899bc1b4a7c9aa76fb1" member_type: VOTER last_known_addr { host: "127.2.110.1" port: 43355 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:24.176493  2488 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.011s	sys 0.013s
I20260812 06:18:24.326025  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushMRSOp(d976d8846d21441bb7cd193eeabd79df): perf score=19.054940
I20260812 06:18:24.495173  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushMRSOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.169s	user 0.129s	sys 0.028s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":228,"dirs.run_cpu_time_us":170,"dirs.run_wall_time_us":737,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44127,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:24.495832  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling LogGCOp(d976d8846d21441bb7cd193eeabd79df): free 20743831 bytes of WAL
I20260812 06:18:24.496085  2937 log_reader.cc:385] T d976d8846d21441bb7cd193eeabd79df: removed 2 log segments from log reader
I20260812 06:18:24.496155  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000001 (ops 1-6)
I20260812 06:18:24.496208  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000002 (ops 7-11)
I20260812 06:18:24.500685  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: LogGCOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:24.501259  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:24.519085  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.018s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7426,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.519518  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:24.673892  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.154s	user 0.115s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":310,"lbm_read_time_us":11861,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26330,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":310,"threads_started":5,"update_count":2000}
I20260812 06:18:24.674446  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling UndoDeltaBlockGCOp(d976d8846d21441bb7cd193eeabd79df): 16411394 bytes on disk
I20260812 06:18:24.674903  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: UndoDeltaBlockGCOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:18:24.675338  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=14.095187
I20260812 06:18:24.736366  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.061s	user 0.018s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25892,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.736979  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:24.751055  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5104,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.751529  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:24.940236  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.189s	user 0.126s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":814,"lbm_read_time_us":12609,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32700,"lbm_writes_lt_1ms":543,"mutex_wait_us":391,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:18:24.940896  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=14.095187
I20260812 06:18:25.010463  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.069s	user 0.036s	sys 0.016s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":25644,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.011013  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:25.022455  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4585,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.023059  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:25.221601  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.198s	user 0.130s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":408,"lbm_read_time_us":16545,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31388,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":34304,"update_count":2500}
I20260812 06:18:25.222368  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=14.095187
I20260812 06:18:25.285159  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.062s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19915,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.285703  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:25.296962  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4340,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.297588  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:25.491218  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.193s	user 0.117s	sys 0.076s 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":1239,"lbm_read_time_us":13215,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32678,"lbm_writes_lt_1ms":543,"mutex_wait_us":358,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:25.495282  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=14.095187
I20260812 06:18:25.562196  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.067s	user 0.036s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23555,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.563762  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:25.579671  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.016s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6219,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.580142  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:25.771967  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.192s	user 0.111s	sys 0.080s 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":751,"lbm_read_time_us":13998,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34518,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:18:25.772518  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=11.118625
I20260812 06:18:25.814373  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.042s	user 0.014s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18423,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:25.815197  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:25.835428  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.020s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5926,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:25.835999  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushMRSOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:25.889123  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushMRSOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.053s	user 0.037s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1296,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2469,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:25.889801  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling LogGCOp(d976d8846d21441bb7cd193eeabd79df): free 108535498 bytes of WAL
I20260812 06:18:25.890044  2937 log_reader.cc:385] T d976d8846d21441bb7cd193eeabd79df: removed 11 log segments from log reader
I20260812 06:18:25.890108  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000003 (ops 12-16)
I20260812 06:18:25.890159  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000004 (ops 17-21)
I20260812 06:18:25.890193  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000005 (ops 22-26)
I20260812 06:18:25.890247  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000006 (ops 27-30)
I20260812 06:18:25.890296  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000007 (ops 31-35)
I20260812 06:18:25.890331  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000008 (ops 36-40)
I20260812 06:18:25.890372  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000009 (ops 41-45)
I20260812 06:18:25.890413  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000010 (ops 46-50)
I20260812 06:18:25.890456  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000011 (ops 51-54)
I20260812 06:18:25.890498  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000012 (ops 55-59)
I20260812 06:18:25.890540  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000013 (ops 60-64)
I20260812 06:18:25.917604  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: LogGCOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:25.917982  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=6.157687
I20260812 06:18:25.947589  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.029s	user 0.018s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11469,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:25.948125  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling LogGCOp(d976d8846d21441bb7cd193eeabd79df): free 11564875 bytes of WAL
I20260812 06:18:25.948534  2937 log_reader.cc:385] T d976d8846d21441bb7cd193eeabd79df: removed 1 log segments from log reader
I20260812 06:18:25.948632  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000014 (ops 65-68)
I20260812 06:18:25.951043  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: LogGCOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:25.951324  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:26.175302  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.224s	user 0.134s	sys 0.089s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877212,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2019,"lbm_read_time_us":15240,"lbm_reads_lt_1ms":665,"lbm_write_time_us":37113,"lbm_writes_lt_1ms":643,"mutex_wait_us":359,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":47872,"thread_start_us":116,"threads_started":1,"update_count":3000}
I20260812 06:18:26.176213  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=18.063937
I20260812 06:18:26.246171  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.070s	user 0.027s	sys 0.029s Metrics: {"bytes_written":20512313,"delete_count":0,"lbm_write_time_us":27467,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:26.246829  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:26.259876  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.013s	user 0.010s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4866,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.260342  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:26.487581  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.227s	user 0.152s	sys 0.074s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1942,"lbm_read_time_us":18756,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35608,"lbm_writes_lt_1ms":643,"mutex_wait_us":661,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":37888,"update_count":3000}
I20260812 06:18:26.488286  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling UndoDeltaBlockGCOp(d976d8846d21441bb7cd193eeabd79df): 462 bytes on disk
I20260812 06:18:26.488775  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: UndoDeltaBlockGCOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:18:26.489308  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=18.063937
I20260812 06:18:26.558467  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.069s	user 0.028s	sys 0.027s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27233,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:26.559032  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:26.570775  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4464,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.571251  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:26.816109  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.245s	user 0.151s	sys 0.081s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1215,"lbm_read_time_us":16632,"lbm_reads_lt_1ms":672,"lbm_write_time_us":40521,"lbm_writes_lt_1ms":643,"mutex_wait_us":845,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":26752,"update_count":3000}
I20260812 06:18:26.816792  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=18.063937
I20260812 06:18:26.900236  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.083s	user 0.040s	sys 0.032s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":33676,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:26.900985  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:26.916648  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5912,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.917423  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:27.151798  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.234s	user 0.163s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":269,"lbm_read_time_us":17605,"lbm_reads_lt_1ms":664,"lbm_write_time_us":37356,"lbm_writes_lt_1ms":643,"mutex_wait_us":13,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":3000}
I20260812 06:18:27.152623  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=16.079562
I20260812 06:18:27.210809  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.058s	user 0.041s	sys 0.013s Metrics: {"bytes_written":18584181,"delete_count":0,"lbm_write_time_us":26377,"lbm_writes_lt_1ms":456,"mutex_wait_us":678,"reinsert_count":0,"update_count":2265}
I20260812 06:18:27.211558  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.196750
I20260812 06:18:27.234733  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.023s	user 0.009s	sys 0.001s Metrics: {"bytes_written":2338583,"delete_count":0,"lbm_write_time_us":4171,"lbm_writes_lt_1ms":60,"reinsert_count":0,"update_count":285}
I20260812 06:18:27.235217  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:27.245939  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.011s	user 0.003s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4379,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:27.246441  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:27.477882  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.231s	user 0.145s	sys 0.085s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877169,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":944,"lbm_read_time_us":17501,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38340,"lbm_writes_lt_1ms":643,"mutex_wait_us":311,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:18:27.479456  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=17.071750
I20260812 06:18:27.560050  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.080s	user 0.029s	sys 0.041s Metrics: {"bytes_written":18830323,"delete_count":0,"lbm_write_time_us":34381,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":461,"mutex_wait_us":41,"reinsert_count":0,"update_count":2295}
I20260812 06:18:27.560540  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=4.173312
I20260812 06:18:27.587558  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.027s	user 0.011s	sys 0.009s Metrics: {"bytes_written":5784663,"delete_count":0,"lbm_write_time_us":8334,"lbm_writes_lt_1ms":144,"reinsert_count":0,"update_count":705}
I20260812 06:18:27.588137  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushMRSOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:27.645408  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushMRSOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.057s	user 0.032s	sys 0.003s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":105,"dirs.run_cpu_time_us":263,"dirs.run_wall_time_us":1390,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2374,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:27.646157  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling LogGCOp(d976d8846d21441bb7cd193eeabd79df): free 129320526 bytes of WAL
I20260812 06:18:27.646431  2937 log_reader.cc:385] T d976d8846d21441bb7cd193eeabd79df: removed 13 log segments from log reader
I20260812 06:18:27.646504  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000015 (ops 69-73)
I20260812 06:18:27.646560  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000016 (ops 74-78)
I20260812 06:18:27.646600  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000017 (ops 79-83)
I20260812 06:18:27.646642  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000018 (ops 84-88)
I20260812 06:18:27.646682  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000019 (ops 89-92)
I20260812 06:18:27.646723  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000020 (ops 93-97)
I20260812 06:18:27.646762  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000021 (ops 98-102)
I20260812 06:18:27.646801  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000022 (ops 103-107)
I20260812 06:18:27.646842  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000023 (ops 108-112)
I20260812 06:18:27.646881  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000024 (ops 113-116)
I20260812 06:18:27.646953  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000025 (ops 117-121)
I20260812 06:18:27.646994  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000026 (ops 122-126)
I20260812 06:18:27.647034  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000027 (ops 127-131)
I20260812 06:18:27.679499  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: LogGCOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.033s	user 0.002s	sys 0.031s Metrics: {}
I20260812 06:18:27.680332  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling UndoDeltaBlockGCOp(d976d8846d21441bb7cd193eeabd79df): 493 bytes on disk
I20260812 06:18:27.681053  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: UndoDeltaBlockGCOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:18:27.682154  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=7.149875
I20260812 06:18:27.711807  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":9107612,"delete_count":0,"lbm_write_time_us":13053,"lbm_writes_lt_1ms":225,"reinsert_count":0,"update_count":1110}
I20260812 06:18:27.712798  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:27.730408  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.017s	user 0.008s	sys 0.002s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":4695,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:18:27.730871  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:28.000243  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.269s	user 0.204s	sys 0.064s Metrics: {"cfile_cache_miss":934,"cfile_cache_miss_bytes":41184563,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":656,"lbm_read_time_us":20709,"lbm_reads_lt_1ms":966,"lbm_write_time_us":48937,"lbm_writes_lt_1ms":943,"mutex_wait_us":27,"peak_mem_usage":112822188,"reinsert_count":0,"spinlock_wait_cycles":22784,"thread_start_us":486,"threads_started":6,"update_count":4500}
I20260812 06:18:28.001313  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=22.032687
I20260812 06:18:28.085971  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.084s	user 0.033s	sys 0.046s Metrics: {"bytes_written":24614721,"delete_count":0,"lbm_write_time_us":36597,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:18:28.086647  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=3.181125
I20260812 06:18:28.108521  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.022s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7517,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:28.108989  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:28.119127  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4062,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:28.119555  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:28.342353  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.223s	user 0.173s	sys 0.047s Metrics: {"cfile_cache_miss":833,"cfile_cache_miss_bytes":37082029,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":311,"lbm_read_time_us":18515,"lbm_reads_lt_1ms":873,"lbm_write_time_us":46725,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":51584,"update_count":4000}
I20260812 06:18:28.343076  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=18.063937
I20260812 06:18:28.417263  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.074s	user 0.029s	sys 0.040s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":33957,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":500,"reinsert_count":0,"update_count":2500}
I20260812 06:18:28.417799  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=3.181125
I20260812 06:18:28.431771  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4882125,"delete_count":0,"lbm_write_time_us":6003,"lbm_writes_lt_1ms":122,"reinsert_count":0,"update_count":595}
I20260812 06:18:28.432268  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:28.442498  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3323180,"delete_count":0,"lbm_write_time_us":3558,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:18:28.443145  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:28.651019  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.208s	user 0.169s	sys 0.039s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979619,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":138,"lbm_read_time_us":14410,"lbm_reads_lt_1ms":773,"lbm_write_time_us":44245,"lbm_writes_lt_1ms":743,"mutex_wait_us":3,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":3500}
I20260812 06:18:28.651718  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=14.095187
I20260812 06:18:28.703079  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.051s	user 0.026s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21670,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.703604  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:28.732143  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.028s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5916,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.732616  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:28.743999  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3995,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.744405  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:28.920214  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.176s	user 0.128s	sys 0.047s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1588,"lbm_read_time_us":14955,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33420,"lbm_writes_lt_1ms":643,"mutex_wait_us":526,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":3000}
I20260812 06:18:28.920826  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=14.095187
I20260812 06:18:28.978883  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.058s	user 0.021s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22090,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.979856  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:28.994992  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.015s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5652,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.995553  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushMRSOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:29.025082  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushMRSOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":134,"dirs.run_cpu_time_us":291,"dirs.run_wall_time_us":1365,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1770,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:29.025856  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling LogGCOp(d976d8846d21441bb7cd193eeabd79df): free 112239518 bytes of WAL
I20260812 06:18:29.026095  2937 log_reader.cc:385] T d976d8846d21441bb7cd193eeabd79df: removed 11 log segments from log reader
I20260812 06:18:29.026144  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000028 (ops 132-136)
I20260812 06:18:29.026185  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000029 (ops 137-140)
I20260812 06:18:29.026257  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000030 (ops 141-145)
I20260812 06:18:29.026327  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000031 (ops 146-150)
I20260812 06:18:29.026373  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000032 (ops 151-155)
I20260812 06:18:29.026439  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000033 (ops 156-160)
I20260812 06:18:29.026473  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000034 (ops 161-165)
I20260812 06:18:29.026518  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000035 (ops 166-170)
I20260812 06:18:29.026567  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000036 (ops 171-175)
I20260812 06:18:29.026598  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000037 (ops 176-180)
I20260812 06:18:29.026633  2937 log.cc:1079] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: Deleting log segment in path: /tmp/dist-test-task500yS8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515498237241-2488-0/minicluster-data/ts-0-root/wals/d976d8846d21441bb7cd193eeabd79df/wal-000000038 (ops 181-185)
I20260812 06:18:29.052529  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: LogGCOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.026s	user 0.003s	sys 0.022s Metrics: {}
I20260812 06:18:29.052945  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=4.173312
I20260812 06:18:29.069716  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":5497489,"delete_count":0,"lbm_write_time_us":7220,"lbm_writes_lt_1ms":137,"reinsert_count":0,"update_count":670}
I20260812 06:18:29.070196  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling UndoDeltaBlockGCOp(d976d8846d21441bb7cd193eeabd79df): 447 bytes on disk
I20260812 06:18:29.070631  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: UndoDeltaBlockGCOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:18:29.071199  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.196750
I20260812 06:18:29.087996  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.017s	user 0.007s	sys 0.005s Metrics: {"bytes_written":2707805,"delete_count":0,"lbm_write_time_us":4361,"lbm_writes_lt_1ms":69,"reinsert_count":0,"update_count":330}
I20260812 06:18:29.088714  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df): perf score=1.000000
I20260812 06:18:29.280120  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: MajorDeltaCompactionOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.191s	user 0.153s	sys 0.036s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979720,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1893,"lbm_read_time_us":15594,"lbm_reads_lt_1ms":770,"lbm_write_time_us":39755,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:18:29.280907  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=14.095187
I20260812 06:18:29.310593  2488 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.134s	user 1.935s	sys 0.186s
I20260812 06:18:29.346042  2488 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.035s	user 0.000s	sys 0.001s
I20260812 06:18:29.346603  2488 tablet_server.cc:179] TabletServer@127.2.110.1:0 shutting down...
I20260812 06:18:29.348599  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.067s	user 0.030s	sys 0.035s Metrics: {"bytes_written":16409912,"delete_count":0,"lbm_write_time_us":32931,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:18:29.349584  3038 maintenance_manager.cc:419] P 12258b8498104899bc1b4a7c9aa76fb1: Scheduling FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df): perf score=2.188937
I20260812 06:18:29.364050  2937 maintenance_manager.cc:643] P 12258b8498104899bc1b4a7c9aa76fb1: FlushDeltaMemStoresOp(d976d8846d21441bb7cd193eeabd79df) complete. Timing: real 0.014s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6006,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.364574  2488 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:29.364799  2488 tablet_replica.cc:333] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1: stopping tablet replica
I20260812 06:18:29.364948  2488 raft_consensus.cc:2243] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:29.365106  2488 raft_consensus.cc:2272] T d976d8846d21441bb7cd193eeabd79df P 12258b8498104899bc1b4a7c9aa76fb1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:29.368592  2488 tablet_server.cc:196] TabletServer@127.2.110.1:0 shutdown complete.
I20260812 06:18:29.371431  2488 master.cc:562] Master@127.2.110.62:36051 shutting down...
I20260812 06:18:29.374972  2488 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:29.375129  2488 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:29.375203  2488 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4637955f8c54429d878b40807c3fdab0: stopping tablet replica
I20260812 06:18:29.388063  2488 master.cc:584] Master@127.2.110.62:36051 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5555 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11239 ms total)

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