[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:36.702782 20021 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.141.126:43463
I20260812 06:19:36.703733 20021 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:36.704313 20021 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:36.710492 20031 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:36.710572 20021 server_base.cc:1061] running on GCE node
W20260812 06:19:36.710480 20027 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:36.710743 20029 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:36.711225 20021 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:36.711315 20021 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:36.711344 20021 hybrid_clock.cc:648] HybridClock initialized: now 1786515576711343 us; error 0 us; skew 500 ppm
I20260812 06:19:36.713078 20021 webserver.cc:533] Webserver started at http://127.19.141.126:36847/ using document root <none> and password file <none>
I20260812 06:19:36.713593 20021 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:36.713650 20021 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:36.713845 20021 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:36.715417 20021 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/master-0-root/instance:
uuid: "9cfcce6d7b4249eda2407a90ba854b76"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-k5rr"
I20260812 06:19:36.718820 20021 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:36.720896 20043 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:36.721913 20021 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:36.722023 20021 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/master-0-root
uuid: "9cfcce6d7b4249eda2407a90ba854b76"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-k5rr"
I20260812 06:19:36.722112 20021 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:36.739820 20021 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:36.740492 20021 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:36.740655 20021 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:36.747964 20021 rpc_server.cc:307] RPC server started. Bound to: 127.19.141.126:43463
I20260812 06:19:36.747970 20145 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.141.126:43463 every 8 connection(s)
I20260812 06:19:36.750231 20146 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:36.755852 20146 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76: Bootstrap starting.
I20260812 06:19:36.758239 20146 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:36.759117 20146 log.cc:826] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:36.760744 20146 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76: No bootstrap required, opened a new log
I20260812 06:19:36.763528 20146 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9cfcce6d7b4249eda2407a90ba854b76" member_type: VOTER }
I20260812 06:19:36.763691 20146 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:36.763767 20146 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9cfcce6d7b4249eda2407a90ba854b76, State: Initialized, Role: FOLLOWER
I20260812 06:19:36.764364 20146 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [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: "9cfcce6d7b4249eda2407a90ba854b76" member_type: VOTER }
I20260812 06:19:36.764526 20146 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:36.764596 20146 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:36.764724 20146 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:36.765547 20146 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9cfcce6d7b4249eda2407a90ba854b76" member_type: VOTER }
I20260812 06:19:36.765969 20146 leader_election.cc:304] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [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: 9cfcce6d7b4249eda2407a90ba854b76; no voters: 
I20260812 06:19:36.766284 20146 leader_election.cc:290] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:36.766383 20149 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:36.766587 20149 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [term 1 LEADER]: Becoming Leader. State: Replica: 9cfcce6d7b4249eda2407a90ba854b76, State: Running, Role: LEADER
I20260812 06:19:36.766979 20149 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [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: "9cfcce6d7b4249eda2407a90ba854b76" member_type: VOTER }
I20260812 06:19:36.767253 20146 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:36.768759 20151 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9cfcce6d7b4249eda2407a90ba854b76. Latest consensus state: current_term: 1 leader_uuid: "9cfcce6d7b4249eda2407a90ba854b76" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9cfcce6d7b4249eda2407a90ba854b76" member_type: VOTER } }
I20260812 06:19:36.768795 20150 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9cfcce6d7b4249eda2407a90ba854b76" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9cfcce6d7b4249eda2407a90ba854b76" member_type: VOTER } }
I20260812 06:19:36.768869 20151 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:36.768893 20150 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:36.769577 20021 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:19:36.771593 20175 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:36.771662 20175 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:36.771754 20168 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:36.772490 20168 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:36.777272 20168 catalog_manager.cc:1383] Generated new cluster ID: 554f0995afeb4dd4b553f5ccdc41bf64
I20260812 06:19:36.777354 20168 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:36.794323 20168 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:36.795161 20168 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:36.806247 20168 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76: Generated new TSK 0
I20260812 06:19:36.807096 20168 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:36.834538 20021 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:36.837416 20190 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:36.837558 20021 server_base.cc:1061] running on GCE node
W20260812 06:19:36.837463 20186 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:36.837416 20184 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:19:36.837926 20021 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:36.837975 20021 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:36.837996 20021 hybrid_clock.cc:648] HybridClock initialized: now 1786515576837995 us; error 0 us; skew 500 ppm
I20260812 06:19:36.838878 20021 webserver.cc:533] Webserver started at http://127.19.141.65:42579/ using document root <none> and password file <none>
I20260812 06:19:36.839053 20021 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:36.839107 20021 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:36.839183 20021 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:36.839560 20021 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/instance:
uuid: "ea55f1733c064b609837971b17594b97"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-k5rr"
I20260812 06:19:36.841039 20021 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:36.842000 20199 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:36.842264 20021 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:36.842334 20021 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root
uuid: "ea55f1733c064b609837971b17594b97"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-k5rr"
I20260812 06:19:36.842406 20021 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:36.852073 20021 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:36.852461 20021 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:36.853266 20021 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:36.854104 20021 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:36.854158 20021 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:36.854204 20021 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:36.854233 20021 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:36.860424 20021 rpc_server.cc:307] RPC server started. Bound to: 127.19.141.65:40039
I20260812 06:19:36.860471 20300 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.141.65:40039 every 8 connection(s)
I20260812 06:19:36.872573 20301 heartbeater.cc:344] Connected to a master server at 127.19.141.126:43463
I20260812 06:19:36.872824 20301 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:36.873340 20301 heartbeater.cc:507] Master 127.19.141.126:43463 requested a full tablet report, sending...
I20260812 06:19:36.874748 20080 ts_manager.cc:194] Registered new tserver with Master: ea55f1733c064b609837971b17594b97 (127.19.141.65:40039)
I20260812 06:19:36.875566 20021 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014468995s
I20260812 06:19:36.876014 20080 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47594
I20260812 06:19:36.884534 20080 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47610:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:36.898336 20247 tablet_service.cc:1511] Processing CreateTablet for tablet db11dc87c94e4d00b15599d3ad79362a (DEFAULT_TABLE table=heavy-update-compaction-test [id=b87d57996bd549deae380b49a6053dc5]), partition=
I20260812 06:19:36.898738 20247 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet db11dc87c94e4d00b15599d3ad79362a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:36.901129 20320 tablet_bootstrap.cc:492] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Bootstrap starting.
I20260812 06:19:36.902050 20320 tablet_bootstrap.cc:654] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:36.903571 20320 tablet_bootstrap.cc:492] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: No bootstrap required, opened a new log
I20260812 06:19:36.903667 20320 ts_tablet_manager.cc:1403] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:36.904088 20320 raft_consensus.cc:359] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ea55f1733c064b609837971b17594b97" member_type: VOTER last_known_addr { host: "127.19.141.65" port: 40039 } }
I20260812 06:19:36.904182 20320 raft_consensus.cc:385] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:36.904214 20320 raft_consensus.cc:740] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ea55f1733c064b609837971b17594b97, State: Initialized, Role: FOLLOWER
I20260812 06:19:36.904345 20320 consensus_queue.cc:260] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97 [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: "ea55f1733c064b609837971b17594b97" member_type: VOTER last_known_addr { host: "127.19.141.65" port: 40039 } }
I20260812 06:19:36.904415 20320 raft_consensus.cc:399] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:36.904456 20320 raft_consensus.cc:493] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:36.904503 20320 raft_consensus.cc:3060] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:36.905264 20320 raft_consensus.cc:515] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ea55f1733c064b609837971b17594b97" member_type: VOTER last_known_addr { host: "127.19.141.65" port: 40039 } }
I20260812 06:19:36.905395 20320 leader_election.cc:304] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97 [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: ea55f1733c064b609837971b17594b97; no voters: 
I20260812 06:19:36.905562 20320 leader_election.cc:290] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:36.905673 20324 raft_consensus.cc:2804] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:36.905886 20320 ts_tablet_manager.cc:1434] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:36.906098 20301 heartbeater.cc:499] Master 127.19.141.126:43463 was elected leader, sending a full tablet report...
I20260812 06:19:36.905910 20324 raft_consensus.cc:697] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97 [term 1 LEADER]: Becoming Leader. State: Replica: ea55f1733c064b609837971b17594b97, State: Running, Role: LEADER
I20260812 06:19:36.906454 20324 consensus_queue.cc:237] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97 [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: "ea55f1733c064b609837971b17594b97" member_type: VOTER last_known_addr { host: "127.19.141.65" port: 40039 } }
I20260812 06:19:36.909061 20080 catalog_manager.cc:5719] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97 reported cstate change: term changed from 0 to 1, leader changed from <none> to ea55f1733c064b609837971b17594b97 (127.19.141.65). New cstate: current_term: 1 leader_uuid: "ea55f1733c064b609837971b17594b97" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ea55f1733c064b609837971b17594b97" member_type: VOTER last_known_addr { host: "127.19.141.65" port: 40039 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:36.964752 20021 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.020s	sys 0.003s
I20260812 06:19:37.111686 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushMRSOp(db11dc87c94e4d00b15599d3ad79362a): perf score=19.054940
I20260812 06:19:37.273280 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushMRSOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.161s	user 0.129s	sys 0.032s Metrics: {"bytes_written":12553636,"cfile_init":1,"compiler_manager_pool.queue_time_us":218,"delete_count":0,"dirs.queue_time_us":43,"dirs.run_cpu_time_us":160,"dirs.run_wall_time_us":1548,"drs_written":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38320,"lbm_writes_lt_1ms":773,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":106,"threads_started":1,"update_count":1530}
I20260812 06:19:37.274369 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling LogGCOp(db11dc87c94e4d00b15599d3ad79362a): free 20743880 bytes of WAL
I20260812 06:19:37.274655 20210 log_reader.cc:385] T db11dc87c94e4d00b15599d3ad79362a: removed 2 log segments from log reader
I20260812 06:19:37.274712 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000001 (ops 1-6)
I20260812 06:19:37.274801 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000002 (ops 7-11)
I20260812 06:19:37.278427 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: LogGCOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:37.278798 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:37.296648 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.018s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3446255,"delete_count":0,"lbm_write_time_us":5327,"lbm_writes_lt_1ms":87,"reinsert_count":0,"update_count":420}
I20260812 06:19:37.297224 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:37.431701 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.134s	user 0.090s	sys 0.041s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20303014,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":491,"lbm_read_time_us":6981,"lbm_reads_lt_1ms":454,"lbm_write_time_us":21183,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"thread_start_us":308,"threads_started":5,"update_count":1950}
I20260812 06:19:37.432422 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling UndoDeltaBlockGCOp(db11dc87c94e4d00b15599d3ad79362a): 16821645 bytes on disk
I20260812 06:19:37.433456 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: UndoDeltaBlockGCOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:37.434015 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=11.118625
I20260812 06:19:37.471328 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.037s	user 0.030s	sys 0.005s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15902,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:37.471897 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:37.485260 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4422,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:37.485888 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:37.603818 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.117s	user 0.089s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713265,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":167,"lbm_read_time_us":8011,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22021,"lbm_writes_lt_1ms":443,"mutex_wait_us":35,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":2000}
I20260812 06:19:37.605561 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=10.126437
I20260812 06:19:37.643108 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.037s	user 0.022s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16114,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.643642 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:37.654134 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3520,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.654680 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:37.770516 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.116s	user 0.105s	sys 0.010s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":346,"lbm_read_time_us":7425,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22867,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:19:37.770994 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=10.126437
I20260812 06:19:37.817804 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.046s	user 0.017s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15714,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.818463 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:37.833220 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.015s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5505,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.833752 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:37.976645 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.143s	user 0.096s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":578,"lbm_read_time_us":11174,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24128,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":124032,"update_count":2000}
I20260812 06:19:37.977267 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=10.126437
I20260812 06:19:38.021543 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.044s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13352,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.022056 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:38.032341 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3668,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.032984 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:38.153769 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.121s	user 0.092s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":253,"lbm_read_time_us":9610,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21948,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:38.154255 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=10.126437
I20260812 06:19:38.195685 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.041s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15970,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.196192 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:38.206149 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3649,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.206688 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:38.325971 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.119s	user 0.091s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":780,"lbm_read_time_us":8046,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23152,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20608,"update_count":2000}
I20260812 06:19:38.326475 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=10.126437
I20260812 06:19:38.376271 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.050s	user 0.025s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15217,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.376844 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:38.386726 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3663,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.387156 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:38.521603 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.134s	user 0.082s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":666,"lbm_read_time_us":10321,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21556,"lbm_writes_lt_1ms":443,"mutex_wait_us":311,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:38.522202 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=10.126437
I20260812 06:19:38.561829 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.039s	user 0.030s	sys 0.003s Metrics: {"bytes_written":12307495,"delete_count":0,"lbm_write_time_us":14491,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.562330 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:38.579440 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.017s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6573,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.579952 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushMRSOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:38.608865 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushMRSOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":1148,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1545,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:38.609879 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling LogGCOp(db11dc87c94e4d00b15599d3ad79362a): free 124710293 bytes of WAL
I20260812 06:19:38.610116 20210 log_reader.cc:385] T db11dc87c94e4d00b15599d3ad79362a: removed 12 log segments from log reader
I20260812 06:19:38.610169 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000003 (ops 12-16)
I20260812 06:19:38.610219 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000004 (ops 17-21)
I20260812 06:19:38.610248 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000005 (ops 22-26)
I20260812 06:19:38.610284 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000006 (ops 27-31)
I20260812 06:19:38.610311 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000007 (ops 32-36)
I20260812 06:19:38.610337 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000008 (ops 37-41)
I20260812 06:19:38.610363 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000009 (ops 42-46)
I20260812 06:19:38.610388 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000010 (ops 47-51)
I20260812 06:19:38.610409 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000011 (ops 52-56)
I20260812 06:19:38.610432 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000012 (ops 57-61)
I20260812 06:19:38.610458 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000013 (ops 62-66)
I20260812 06:19:38.610484 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000014 (ops 67-71)
I20260812 06:19:38.631954 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: LogGCOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.022s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:19:38.632405 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling UndoDeltaBlockGCOp(db11dc87c94e4d00b15599d3ad79362a): 483 bytes on disk
I20260812 06:19:38.632800 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: UndoDeltaBlockGCOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:38.633535 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=3.181125
I20260812 06:19:38.655714 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.022s	user 0.001s	sys 0.016s Metrics: {"bytes_written":4307780,"delete_count":0,"lbm_write_time_us":3913,"lbm_writes_lt_1ms":108,"reinsert_count":0,"update_count":525}
I20260812 06:19:38.656162 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:38.670444 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":5177,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:19:38.670930 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:38.868675 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.198s	user 0.128s	sys 0.064s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918335,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2076,"lbm_read_time_us":14863,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33256,"lbm_writes_lt_1ms":643,"mutex_wait_us":827,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":71,"threads_started":1,"update_count":3000}
I20260812 06:19:38.869305 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=11.118625
I20260812 06:19:38.914125 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.045s	user 0.027s	sys 0.016s Metrics: {"bytes_written":13374124,"delete_count":0,"lbm_write_time_us":19896,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":327,"reinsert_count":0,"update_count":1630}
I20260812 06:19:38.914630 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:38.932070 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.017s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3446259,"delete_count":0,"lbm_write_time_us":3209,"lbm_writes_lt_1ms":87,"reinsert_count":0,"update_count":420}
I20260812 06:19:38.932519 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:38.941749 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3308,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:38.942167 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:39.103156 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.161s	user 0.123s	sys 0.035s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815783,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1106,"lbm_read_time_us":13677,"lbm_reads_lt_1ms":573,"lbm_write_time_us":24729,"lbm_writes_lt_1ms":543,"mutex_wait_us":316,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:39.103739 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=11.118625
I20260812 06:19:39.132474 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.029s	user 0.015s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12124,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:39.133265 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:39.150704 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.017s	user 0.004s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6299,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.151288 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:39.279457 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.128s	user 0.108s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":197,"lbm_read_time_us":8894,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24437,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20864,"update_count":2000}
I20260812 06:19:39.280249 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=11.118625
I20260812 06:19:39.316733 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.036s	user 0.019s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15503,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:19:39.317306 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:39.334493 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.017s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3999,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.334928 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:39.344120 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3200,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.344586 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:39.475745 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.131s	user 0.102s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":463,"lbm_read_time_us":8922,"lbm_reads_lt_1ms":573,"lbm_write_time_us":25224,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":37760,"update_count":2500}
I20260812 06:19:39.476477 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=10.126437
I20260812 06:19:39.512789 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.036s	user 0.026s	sys 0.003s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16290,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:39.513338 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:39.528028 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.015s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5235,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.529400 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:39.652803 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.123s	user 0.101s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":896,"lbm_read_time_us":9562,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20975,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:19:39.653436 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=10.126437
I20260812 06:19:39.700343 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.047s	user 0.025s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16534,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:39.700953 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:39.716168 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5630,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.716657 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:39.848587 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.132s	user 0.100s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":552,"lbm_read_time_us":10207,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21850,"lbm_writes_lt_1ms":443,"mutex_wait_us":293,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.849143 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=10.126437
I20260812 06:19:39.886044 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.037s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14836,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:39.886492 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:39.897166 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3598,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.897630 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushMRSOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:39.923303 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushMRSOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.026s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":206,"dirs.run_wall_time_us":1078,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1560,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:39.924155 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling LogGCOp(db11dc87c94e4d00b15599d3ad79362a): free 121006461 bytes of WAL
I20260812 06:19:39.924398 20210 log_reader.cc:385] T db11dc87c94e4d00b15599d3ad79362a: removed 12 log segments from log reader
I20260812 06:19:39.924450 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000015 (ops 72-76)
I20260812 06:19:39.924489 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000016 (ops 77-81)
I20260812 06:19:39.924521 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000017 (ops 82-86)
I20260812 06:19:39.924552 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000018 (ops 87-91)
I20260812 06:19:39.924582 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000019 (ops 92-96)
I20260812 06:19:39.924612 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000020 (ops 97-100)
I20260812 06:19:39.924642 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000021 (ops 101-105)
I20260812 06:19:39.924671 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000022 (ops 106-110)
I20260812 06:19:39.924700 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000023 (ops 111-115)
I20260812 06:19:39.924729 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000024 (ops 116-120)
I20260812 06:19:39.924758 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000025 (ops 121-125)
I20260812 06:19:39.924788 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000026 (ops 126-130)
I20260812 06:19:39.947544 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: LogGCOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:39.947957 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=3.181125
I20260812 06:19:39.971329 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.023s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":6705,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:39.971786 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:39.980969 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3443,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.981479 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling UndoDeltaBlockGCOp(db11dc87c94e4d00b15599d3ad79362a): 447 bytes on disk
I20260812 06:19:39.981921 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: UndoDeltaBlockGCOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:39.982831 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:40.164515 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.181s	user 0.130s	sys 0.049s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918321,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":486,"lbm_read_time_us":13998,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30746,"lbm_writes_lt_1ms":643,"mutex_wait_us":36,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:19:40.165433 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=14.095187
I20260812 06:19:40.225344 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.059s	user 0.023s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21049,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.226047 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:40.236308 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3841,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.236888 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:40.399534 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.162s	user 0.073s	sys 0.089s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":275,"lbm_read_time_us":13211,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26689,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:19:40.400076 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=10.126437
I20260812 06:19:40.439926 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.040s	user 0.036s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17327,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:40.440428 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:40.452018 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4245,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.452484 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:40.595875 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.143s	user 0.102s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":909,"lbm_read_time_us":9931,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23686,"lbm_writes_lt_1ms":443,"mutex_wait_us":59,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:19:40.596355 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=10.126437
I20260812 06:19:40.646420 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.050s	user 0.016s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15665,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:40.646932 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:40.657111 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3688,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.657734 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:40.777442 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.120s	user 0.090s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1121,"lbm_read_time_us":7929,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21629,"lbm_writes_lt_1ms":443,"mutex_wait_us":334,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:19:40.778116 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=10.126437
I20260812 06:19:40.816203 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.038s	user 0.017s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17379,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:40.816738 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:40.833034 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6116,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.833609 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:40.955224 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.121s	user 0.110s	sys 0.011s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":630,"lbm_read_time_us":7757,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22579,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":2000}
I20260812 06:19:40.956506 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=10.126437
I20260812 06:19:41.001525 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.045s	user 0.025s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16043,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.002046 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:41.012281 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3695,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.012732 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:41.144138 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.131s	user 0.087s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":10329,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21177,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18560,"update_count":2000}
I20260812 06:19:41.144781 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=10.126437
I20260812 06:19:41.184016 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.039s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15393,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.184540 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:41.194579 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3664,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.195245 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:41.311514 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.116s	user 0.089s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":355,"lbm_read_time_us":7497,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22207,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.312130 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=10.126437
I20260812 06:19:41.356102 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.044s	user 0.030s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19529,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.356698 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:41.376382 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.019s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4614,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.376982 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushMRSOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:41.415812 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushMRSOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.039s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":163,"dirs.run_wall_time_us":1011,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1755,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:41.416677 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling UndoDeltaBlockGCOp(db11dc87c94e4d00b15599d3ad79362a): 492 bytes on disk
I20260812 06:19:41.417234 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: UndoDeltaBlockGCOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":97,"lbm_reads_lt_1ms":4}
I20260812 06:19:41.417768 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=3.181125
I20260812 06:19:41.429422 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.011s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":3989,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:41.429943 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling LogGCOp(db11dc87c94e4d00b15599d3ad79362a): free 133024646 bytes of WAL
I20260812 06:19:41.430171 20210 log_reader.cc:385] T db11dc87c94e4d00b15599d3ad79362a: removed 13 log segments from log reader
I20260812 06:19:41.430217 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000027 (ops 131-135)
I20260812 06:19:41.430246 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000028 (ops 136-140)
I20260812 06:19:41.430279 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000029 (ops 141-144)
I20260812 06:19:41.430312 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000030 (ops 145-149)
I20260812 06:19:41.430347 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000031 (ops 150-154)
I20260812 06:19:41.430380 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000032 (ops 155-159)
I20260812 06:19:41.430411 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000033 (ops 160-164)
I20260812 06:19:41.430444 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000034 (ops 165-169)
I20260812 06:19:41.430475 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000035 (ops 170-174)
I20260812 06:19:41.430506 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000036 (ops 175-179)
I20260812 06:19:41.430538 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000037 (ops 180-184)
I20260812 06:19:41.430569 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000038 (ops 185-189)
I20260812 06:19:41.430600 20210 log.cc:1079] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/db11dc87c94e4d00b15599d3ad79362a/wal-000000039 (ops 190-194)
I20260812 06:19:41.455045 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: LogGCOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:41.455502 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:41.474153 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.018s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6036,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.474642 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=2.188937
I20260812 06:19:41.486496 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4541,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:41.486956 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a): perf score=1.000000
I20260812 06:19:41.567683 20021 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.603s	user 1.668s	sys 0.144s
I20260812 06:19:41.664965 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: MajorDeltaCompactionOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.178s	user 0.132s	sys 0.044s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020852,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":2303,"lbm_read_time_us":12955,"lbm_reads_lt_1ms":771,"lbm_write_time_us":33354,"lbm_writes_lt_1ms":743,"mutex_wait_us":1942,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":47744,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:19:41.666230 20303 maintenance_manager.cc:419] P ea55f1733c064b609837971b17594b97: Scheduling FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a): perf score=6.157687
I20260812 06:19:41.667407 20021 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.099s	user 0.002s	sys 0.000s
I20260812 06:19:41.668167 20021 tablet_server.cc:179] TabletServer@127.19.141.65:0 shutting down...
I20260812 06:19:41.687248 20210 maintenance_manager.cc:643] P ea55f1733c064b609837971b17594b97: FlushDeltaMemStoresOp(db11dc87c94e4d00b15599d3ad79362a) complete. Timing: real 0.021s	user 0.007s	sys 0.011s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":8293,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:41.687820 20021 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:41.688249 20021 tablet_replica.cc:333] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97: stopping tablet replica
I20260812 06:19:41.688457 20021 raft_consensus.cc:2243] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:41.688683 20021 raft_consensus.cc:2272] T db11dc87c94e4d00b15599d3ad79362a P ea55f1733c064b609837971b17594b97 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:41.703385 20021 tablet_server.cc:196] TabletServer@127.19.141.65:0 shutdown complete.
I20260812 06:19:41.719864 20021 master.cc:562] Master@127.19.141.126:43463 shutting down...
I20260812 06:19:41.723518 20021 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:41.723701 20021 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:41.723783 20021 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9cfcce6d7b4249eda2407a90ba854b76: stopping tablet replica
I20260812 06:19:41.735973 20021 master.cc:584] Master@127.19.141.126:43463 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5107 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:41.822897 20021 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.141.126:43649
I20260812 06:19:41.823328 20021 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:41.825275 20356 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:41.825213 20365 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:19:41.825383 20362 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:41.825558 20021 server_base.cc:1061] running on GCE node
I20260812 06:19:41.825702 20021 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:41.825737 20021 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:41.825766 20021 hybrid_clock.cc:648] HybridClock initialized: now 1786515581825766 us; error 0 us; skew 500 ppm
I20260812 06:19:41.826540 20021 webserver.cc:533] Webserver started at http://127.19.141.126:42677/ using document root <none> and password file <none>
I20260812 06:19:41.826692 20021 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:41.826737 20021 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:41.826821 20021 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:41.827193 20021 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/master-0-root/instance:
uuid: "3bbdb0a6290549239dee417225cc6c23"
format_stamp: "Formatted at 2026-08-12 06:19:41 on dist-test-slave-k5rr"
I20260812 06:19:41.828606 20021 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:41.830075 20372 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:41.830291 20021 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:19:41.830363 20021 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/master-0-root
uuid: "3bbdb0a6290549239dee417225cc6c23"
format_stamp: "Formatted at 2026-08-12 06:19:41 on dist-test-slave-k5rr"
I20260812 06:19:41.830430 20021 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:41.841854 20021 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:41.842206 20021 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:41.846276 20021 rpc_server.cc:307] RPC server started. Bound to: 127.19.141.126:43649
I20260812 06:19:41.849697 20476 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.141.126:43649 every 8 connection(s)
I20260812 06:19:41.850178 20477 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:41.851907 20477 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23: Bootstrap starting.
I20260812 06:19:41.852629 20477 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:41.853654 20477 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23: No bootstrap required, opened a new log
I20260812 06:19:41.854032 20477 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3bbdb0a6290549239dee417225cc6c23" member_type: VOTER }
I20260812 06:19:41.854117 20477 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:41.854138 20477 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3bbdb0a6290549239dee417225cc6c23, State: Initialized, Role: FOLLOWER
I20260812 06:19:41.854246 20477 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [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: "3bbdb0a6290549239dee417225cc6c23" member_type: VOTER }
I20260812 06:19:41.854301 20477 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:41.854327 20477 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:41.854359 20477 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:41.854984 20477 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3bbdb0a6290549239dee417225cc6c23" member_type: VOTER }
I20260812 06:19:41.855096 20477 leader_election.cc:304] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [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: 3bbdb0a6290549239dee417225cc6c23; no voters: 
I20260812 06:19:41.855222 20477 leader_election.cc:290] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:41.855346 20482 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:41.855530 20482 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [term 1 LEADER]: Becoming Leader. State: Replica: 3bbdb0a6290549239dee417225cc6c23, State: Running, Role: LEADER
I20260812 06:19:41.855626 20477 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:41.855665 20482 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [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: "3bbdb0a6290549239dee417225cc6c23" member_type: VOTER }
I20260812 06:19:41.856046 20484 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3bbdb0a6290549239dee417225cc6c23" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3bbdb0a6290549239dee417225cc6c23" member_type: VOTER } }
I20260812 06:19:41.856077 20486 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3bbdb0a6290549239dee417225cc6c23. Latest consensus state: current_term: 1 leader_uuid: "3bbdb0a6290549239dee417225cc6c23" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3bbdb0a6290549239dee417225cc6c23" member_type: VOTER } }
I20260812 06:19:41.856173 20484 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:41.856189 20486 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:41.856447 20490 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:41.857265 20490 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:41.857510 20021 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:41.858954 20490 catalog_manager.cc:1383] Generated new cluster ID: b01dc51834ce40869f15be397dc39f6b
I20260812 06:19:41.859005 20490 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:41.865603 20490 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:41.866109 20490 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:41.873505 20490 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23: Generated new TSK 0
I20260812 06:19:41.873636 20490 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:41.889652 20021 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:41.891384 20514 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:41.891558 20520 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:19:41.891578 20516 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:41.891645 20021 server_base.cc:1061] running on GCE node
I20260812 06:19:41.891883 20021 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:41.891935 20021 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:41.891948 20021 hybrid_clock.cc:648] HybridClock initialized: now 1786515581891949 us; error 0 us; skew 500 ppm
I20260812 06:19:41.892721 20021 webserver.cc:533] Webserver started at http://127.19.141.65:34347/ using document root <none> and password file <none>
I20260812 06:19:41.892872 20021 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:41.892926 20021 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:41.893030 20021 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:41.893392 20021 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/instance:
uuid: "5978f6b812904d96a6f5cfd61ba33cf5"
format_stamp: "Formatted at 2026-08-12 06:19:41 on dist-test-slave-k5rr"
I20260812 06:19:41.894771 20021 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:41.895625 20526 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:41.895835 20021 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:41.895907 20021 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root
uuid: "5978f6b812904d96a6f5cfd61ba33cf5"
format_stamp: "Formatted at 2026-08-12 06:19:41 on dist-test-slave-k5rr"
I20260812 06:19:41.895977 20021 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:41.907162 20021 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:41.907495 20021 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:41.907756 20021 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:41.908210 20021 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:41.908248 20021 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:41.908289 20021 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:41.908325 20021 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:41.912289 20021 rpc_server.cc:307] RPC server started. Bound to: 127.19.141.65:40623
I20260812 06:19:41.913714 20643 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.141.65:40623 every 8 connection(s)
I20260812 06:19:41.920804 20645 heartbeater.cc:344] Connected to a master server at 127.19.141.126:43649
I20260812 06:19:41.920912 20645 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:41.921149 20645 heartbeater.cc:507] Master 127.19.141.126:43649 requested a full tablet report, sending...
I20260812 06:19:41.921785 20407 ts_manager.cc:194] Registered new tserver with Master: 5978f6b812904d96a6f5cfd61ba33cf5 (127.19.141.65:40623)
I20260812 06:19:41.921837 20021 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008783513s
I20260812 06:19:41.922544 20407 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:59378
I20260812 06:19:41.928156 20407 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:59394:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:41.936473 20579 tablet_service.cc:1511] Processing CreateTablet for tablet c3ecc458c90f4bc38736f781b8f5b694 (DEFAULT_TABLE table=heavy-update-compaction-test [id=8fbc686b8eaf496b81e459d0fa446ff5]), partition=
I20260812 06:19:41.936721 20579 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c3ecc458c90f4bc38736f781b8f5b694. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:41.938637 20664 tablet_bootstrap.cc:492] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Bootstrap starting.
I20260812 06:19:41.939492 20664 tablet_bootstrap.cc:654] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:41.940378 20664 tablet_bootstrap.cc:492] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: No bootstrap required, opened a new log
I20260812 06:19:41.940456 20664 ts_tablet_manager.cc:1403] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:41.940821 20664 raft_consensus.cc:359] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5978f6b812904d96a6f5cfd61ba33cf5" member_type: VOTER last_known_addr { host: "127.19.141.65" port: 40623 } }
I20260812 06:19:41.940923 20664 raft_consensus.cc:385] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:41.940948 20664 raft_consensus.cc:740] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5978f6b812904d96a6f5cfd61ba33cf5, State: Initialized, Role: FOLLOWER
I20260812 06:19:41.941087 20664 consensus_queue.cc:260] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5 [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: "5978f6b812904d96a6f5cfd61ba33cf5" member_type: VOTER last_known_addr { host: "127.19.141.65" port: 40623 } }
I20260812 06:19:41.941164 20664 raft_consensus.cc:399] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:41.941188 20664 raft_consensus.cc:493] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:41.941236 20664 raft_consensus.cc:3060] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:41.942095 20664 raft_consensus.cc:515] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5978f6b812904d96a6f5cfd61ba33cf5" member_type: VOTER last_known_addr { host: "127.19.141.65" port: 40623 } }
I20260812 06:19:41.942219 20664 leader_election.cc:304] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5 [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: 5978f6b812904d96a6f5cfd61ba33cf5; no voters: 
I20260812 06:19:41.942396 20664 leader_election.cc:290] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:41.942502 20667 raft_consensus.cc:2804] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:41.942677 20664 ts_tablet_manager.cc:1434] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:41.942723 20645 heartbeater.cc:499] Master 127.19.141.126:43649 was elected leader, sending a full tablet report...
I20260812 06:19:41.942754 20667 raft_consensus.cc:697] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5 [term 1 LEADER]: Becoming Leader. State: Replica: 5978f6b812904d96a6f5cfd61ba33cf5, State: Running, Role: LEADER
I20260812 06:19:41.942874 20667 consensus_queue.cc:237] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5 [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: "5978f6b812904d96a6f5cfd61ba33cf5" member_type: VOTER last_known_addr { host: "127.19.141.65" port: 40623 } }
I20260812 06:19:41.944119 20407 catalog_manager.cc:5719] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5 reported cstate change: term changed from 0 to 1, leader changed from <none> to 5978f6b812904d96a6f5cfd61ba33cf5 (127.19.141.65). New cstate: current_term: 1 leader_uuid: "5978f6b812904d96a6f5cfd61ba33cf5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5978f6b812904d96a6f5cfd61ba33cf5" member_type: VOTER last_known_addr { host: "127.19.141.65" port: 40623 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:41.996814 20021 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.018s	sys 0.004s
I20260812 06:19:42.164254 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushMRSOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=23.023690
I20260812 06:19:42.316900 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushMRSOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.152s	user 0.098s	sys 0.051s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":725,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40373,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:19:42.317538 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling LogGCOp(c3ecc458c90f4bc38736f781b8f5b694): free 20743880 bytes of WAL
I20260812 06:19:42.317788 20532 log_reader.cc:385] T c3ecc458c90f4bc38736f781b8f5b694: removed 2 log segments from log reader
I20260812 06:19:42.317837 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000001 (ops 1-6)
I20260812 06:19:42.317869 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000002 (ops 7-11)
I20260812 06:19:42.321427 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: LogGCOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:42.321762 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling UndoDeltaBlockGCOp(c3ecc458c90f4bc38736f781b8f5b694): 20513814 bytes on disk
I20260812 06:19:42.322266 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: UndoDeltaBlockGCOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:19:42.322710 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:42.339927 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.017s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4548,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.340408 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:42.354979 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5311,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.355420 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:42.534963 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.179s	user 0.109s	sys 0.067s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815803,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":941,"lbm_read_time_us":11331,"lbm_reads_lt_1ms":569,"lbm_write_time_us":27551,"lbm_writes_lt_1ms":543,"mutex_wait_us":155,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"thread_start_us":310,"threads_started":5,"update_count":2500}
I20260812 06:19:42.535540 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=14.095187
I20260812 06:19:42.586227 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.051s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20258,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.586805 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:42.737674 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.151s	user 0.108s	sys 0.041s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":887,"lbm_read_time_us":10878,"lbm_reads_lt_1ms":463,"lbm_write_time_us":21538,"lbm_writes_lt_1ms":443,"mutex_wait_us":241,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.738216 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=14.095187
I20260812 06:19:42.783190 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.045s	user 0.023s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17854,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.783684 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:42.799520 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6152,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.800194 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:42.984934 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.185s	user 0.117s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":201,"lbm_read_time_us":9715,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29537,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2500}
I20260812 06:19:42.985473 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=14.095187
I20260812 06:19:43.033582 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.048s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18320,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.034215 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:43.045192 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3868,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.045825 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:43.189172 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.143s	user 0.122s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":520,"lbm_read_time_us":10160,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27775,"lbm_writes_lt_1ms":543,"mutex_wait_us":274,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:19:43.189766 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=10.126437
I20260812 06:19:43.219985 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.030s	user 0.010s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12645,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":1500}
I20260812 06:19:43.220503 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:43.235617 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5836,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.236234 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:43.358664 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.122s	user 0.102s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1535,"lbm_read_time_us":8130,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21695,"lbm_writes_lt_1ms":443,"mutex_wait_us":568,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:19:43.359436 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=10.126437
I20260812 06:19:43.397302 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.038s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13567,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:43.397784 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:43.412515 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5143,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.413086 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:43.533623 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.120s	user 0.095s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":273,"lbm_read_time_us":8096,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23621,"lbm_writes_lt_1ms":443,"mutex_wait_us":4,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:19:43.534155 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=10.126437
I20260812 06:19:43.585071 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.051s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14362,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:43.585640 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:43.596122 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3948,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.596704 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushMRSOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:43.639693 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushMRSOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.043s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1124,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1413,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:43.640425 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling LogGCOp(c3ecc458c90f4bc38736f781b8f5b694): free 132571304 bytes of WAL
I20260812 06:19:43.640671 20532 log_reader.cc:385] T c3ecc458c90f4bc38736f781b8f5b694: removed 13 log segments from log reader
I20260812 06:19:43.640722 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000003 (ops 12-16)
I20260812 06:19:43.640750 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000004 (ops 17-21)
I20260812 06:19:43.640767 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000005 (ops 22-26)
I20260812 06:19:43.640795 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000006 (ops 27-31)
I20260812 06:19:43.640827 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000007 (ops 32-36)
I20260812 06:19:43.640852 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000008 (ops 37-40)
I20260812 06:19:43.640885 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000009 (ops 41-45)
I20260812 06:19:43.640908 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000010 (ops 46-50)
I20260812 06:19:43.640938 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000011 (ops 51-55)
I20260812 06:19:43.640970 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000012 (ops 56-60)
I20260812 06:19:43.641001 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000013 (ops 61-65)
I20260812 06:19:43.641062 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000014 (ops 66-70)
I20260812 06:19:43.641093 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000015 (ops 71-74)
I20260812 06:19:43.665419 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: LogGCOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.025s	user 0.006s	sys 0.019s Metrics: {}
I20260812 06:19:43.665838 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling UndoDeltaBlockGCOp(c3ecc458c90f4bc38736f781b8f5b694): 481 bytes on disk
I20260812 06:19:43.666388 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: UndoDeltaBlockGCOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:19:43.667021 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=3.181125
I20260812 06:19:43.682891 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.016s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":3964,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:43.683300 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:43.692399 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3226,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:43.692873 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:43.889532 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.196s	user 0.125s	sys 0.071s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918322,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":460,"lbm_read_time_us":13566,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31219,"lbm_writes_lt_1ms":643,"mutex_wait_us":52,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15360,"thread_start_us":96,"threads_started":1,"update_count":3000}
I20260812 06:19:43.891251 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=14.095187
I20260812 06:19:43.947196 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.056s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20505,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.947670 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:43.958755 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3823,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.959255 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:44.120738 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.161s	user 0.103s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":940,"lbm_read_time_us":10595,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26443,"lbm_writes_lt_1ms":543,"mutex_wait_us":273,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:19:44.121284 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=14.095187
I20260812 06:19:44.178653 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.057s	user 0.013s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17111,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.179162 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:44.189379 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3816,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.189929 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:44.363548 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.173s	user 0.117s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1068,"lbm_read_time_us":12784,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29834,"lbm_writes_lt_1ms":543,"mutex_wait_us":301,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23296,"update_count":2500}
I20260812 06:19:44.364177 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=14.095187
I20260812 06:19:44.418191 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.054s	user 0.038s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17110,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.418757 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:44.432967 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5582,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.433418 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:44.607592 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.174s	user 0.124s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":914,"lbm_read_time_us":11908,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26029,"lbm_writes_lt_1ms":543,"mutex_wait_us":262,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:19:44.608191 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=14.095187
I20260812 06:19:44.675043 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.067s	user 0.030s	sys 0.035s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":26138,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.675665 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:44.686820 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4159,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.687289 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:44.864445 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.177s	user 0.105s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":880,"lbm_read_time_us":12054,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26944,"lbm_writes_lt_1ms":543,"mutex_wait_us":313,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:44.864982 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=14.095187
I20260812 06:19:44.918428 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.053s	user 0.031s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22960,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.919005 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:44.930362 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4051,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.930886 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:45.111068 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.180s	user 0.143s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":250,"lbm_read_time_us":11642,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28569,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:19:45.111603 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=14.095187
I20260812 06:19:45.164458 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.053s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22616,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:45.164968 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:45.175185 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3613,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.175825 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushMRSOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:45.206252 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushMRSOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.030s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1316415,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":140,"dirs.run_wall_time_us":978,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1958,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":17664}
I20260812 06:19:45.206955 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling LogGCOp(c3ecc458c90f4bc38736f781b8f5b694): free 133477412 bytes of WAL
I20260812 06:19:45.207193 20532 log_reader.cc:385] T c3ecc458c90f4bc38736f781b8f5b694: removed 13 log segments from log reader
I20260812 06:19:45.207254 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000016 (ops 75-79)
I20260812 06:19:45.207290 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000017 (ops 80-84)
I20260812 06:19:45.207322 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000018 (ops 85-89)
I20260812 06:19:45.207355 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000019 (ops 90-94)
I20260812 06:19:45.207383 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000020 (ops 95-99)
I20260812 06:19:45.207425 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000021 (ops 100-104)
I20260812 06:19:45.207448 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000022 (ops 105-109)
I20260812 06:19:45.207477 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000023 (ops 110-114)
I20260812 06:19:45.207508 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000024 (ops 115-119)
I20260812 06:19:45.207537 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000025 (ops 120-124)
I20260812 06:19:45.207564 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000026 (ops 125-129)
I20260812 06:19:45.207592 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000027 (ops 130-134)
I20260812 06:19:45.207618 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000028 (ops 135-139)
I20260812 06:19:45.234826 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: LogGCOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:45.235348 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling UndoDeltaBlockGCOp(c3ecc458c90f4bc38736f781b8f5b694): 493 bytes on disk
I20260812 06:19:45.235801 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: UndoDeltaBlockGCOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:19:45.236477 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=3.181125
I20260812 06:19:45.261929 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.025s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4907,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:45.262424 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:45.276095 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.013s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4992,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:45.276630 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:45.494354 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.218s	user 0.143s	sys 0.073s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":481,"lbm_read_time_us":15071,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35614,"lbm_writes_lt_1ms":743,"mutex_wait_us":51,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":90,"threads_started":1,"update_count":3500}
I20260812 06:19:45.494947 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=16.079562
I20260812 06:19:45.555979 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.061s	user 0.039s	sys 0.009s Metrics: {"bytes_written":17927797,"delete_count":0,"lbm_write_time_us":23514,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":438,"reinsert_count":0,"update_count":2185}
I20260812 06:19:45.556571 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=5.165500
I20260812 06:19:45.575157 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":6687189,"delete_count":0,"lbm_write_time_us":7414,"lbm_writes_lt_1ms":166,"reinsert_count":0,"update_count":815}
I20260812 06:19:45.575685 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:45.789294 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.213s	user 0.130s	sys 0.080s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":508,"lbm_read_time_us":15028,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37247,"lbm_writes_lt_1ms":643,"mutex_wait_us":42,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":54144,"update_count":3000}
I20260812 06:19:45.789817 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=18.063937
I20260812 06:19:45.850934 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.061s	user 0.023s	sys 0.032s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26397,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:19:45.851349 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:45.861848 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3748,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.862499 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:46.068957 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.206s	user 0.112s	sys 0.091s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":4066,"lbm_read_time_us":13359,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37256,"lbm_writes_lt_1ms":643,"mutex_wait_us":3302,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":3000}
I20260812 06:19:46.069587 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=15.087375
I20260812 06:19:46.109949 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.040s	user 0.025s	sys 0.014s Metrics: {"bytes_written":16820141,"delete_count":0,"lbm_write_time_us":17261,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:46.110572 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:46.132253 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.021s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4986,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:46.132784 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:46.143815 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4144,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.144520 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:46.361732 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.217s	user 0.146s	sys 0.055s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918199,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":826,"lbm_read_time_us":14716,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38575,"lbm_writes_lt_1ms":643,"mutex_wait_us":311,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:46.365398 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=18.063937
I20260812 06:19:46.425779 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.060s	user 0.037s	sys 0.023s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26795,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:46.426324 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:46.438277 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4258,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.438763 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:46.629171 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: MajorDeltaCompactionOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.190s	user 0.127s	sys 0.063s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":15288,"lbm_reads_lt_1ms":664,"lbm_write_time_us":31160,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":3000}
I20260812 06:19:46.629813 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=14.095187
I20260812 06:19:46.676240 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.046s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20401,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:46.676858 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:46.695861 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.019s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4971,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.696386 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushMRSOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=1.000000
I20260812 06:19:46.707194 20021 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.710s	user 1.712s	sys 0.154s
I20260812 06:19:46.732481 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushMRSOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.036s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1316415,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":163,"dirs.run_wall_time_us":1070,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1562,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:46.733269 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling LogGCOp(c3ecc458c90f4bc38736f781b8f5b694): free 124257565 bytes of WAL
I20260812 06:19:46.733556 20532 log_reader.cc:385] T c3ecc458c90f4bc38736f781b8f5b694: removed 12 log segments from log reader
I20260812 06:19:46.733654 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000029 (ops 140-144)
I20260812 06:19:46.733721 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000030 (ops 145-149)
I20260812 06:19:46.733773 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000031 (ops 150-154)
I20260812 06:19:46.733834 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000032 (ops 155-159)
I20260812 06:19:46.733880 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000033 (ops 160-164)
I20260812 06:19:46.733922 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000034 (ops 165-168)
I20260812 06:19:46.733963 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000035 (ops 169-173)
I20260812 06:19:46.734004 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000036 (ops 174-178)
I20260812 06:19:46.734045 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000037 (ops 179-183)
I20260812 06:19:46.734086 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000038 (ops 184-188)
I20260812 06:19:46.734134 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000039 (ops 189-193)
I20260812 06:19:46.734177 20532 log.cc:1079] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: Deleting log segment in path: /tmp/dist-test-taskXxuoml/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576692172-20021-0/minicluster-data/ts-0-root/wals/c3ecc458c90f4bc38736f781b8f5b694/wal-000000040 (ops 194-198)
I20260812 06:19:46.763643 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: LogGCOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.030s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:46.764130 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling UndoDeltaBlockGCOp(c3ecc458c90f4bc38736f781b8f5b694): 492 bytes on disk
I20260812 06:19:46.764622 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: UndoDeltaBlockGCOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:19:46.765306 20646 maintenance_manager.cc:419] P 5978f6b812904d96a6f5cfd61ba33cf5: Scheduling FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694): perf score=2.188937
I20260812 06:19:46.765852 20021 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.058s	user 0.002s	sys 0.000s
I20260812 06:19:46.766311 20021 tablet_server.cc:179] TabletServer@127.19.141.65:0 shutting down...
I20260812 06:19:46.778648 20532 maintenance_manager.cc:643] P 5978f6b812904d96a6f5cfd61ba33cf5: FlushDeltaMemStoresOp(c3ecc458c90f4bc38736f781b8f5b694) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5112,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.779145 20021 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:46.779356 20021 tablet_replica.cc:333] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5: stopping tablet replica
I20260812 06:19:46.779486 20021 raft_consensus.cc:2243] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:46.779634 20021 raft_consensus.cc:2272] T c3ecc458c90f4bc38736f781b8f5b694 P 5978f6b812904d96a6f5cfd61ba33cf5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:46.782562 20021 tablet_server.cc:196] TabletServer@127.19.141.65:0 shutdown complete.
I20260812 06:19:46.785080 20021 master.cc:562] Master@127.19.141.126:43649 shutting down...
I20260812 06:19:46.788111 20021 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:46.788249 20021 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:46.788323 20021 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3bbdb0a6290549239dee417225cc6c23: stopping tablet replica
I20260812 06:19:46.800287 20021 master.cc:584] Master@127.19.141.126:43649 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5063 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10171 ms total)

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