[==========] 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:29.090476  5532 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.103.62:36123
I20260812 06:19:29.091513  5532 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:29.092108  5532 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:29.098496  5537 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:29.098520  5538 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:29.098757  5532 server_base.cc:1061] running on GCE node
W20260812 06:19:29.098778  5540 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:29.099311  5532 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:29.099442  5532 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:29.099486  5532 hybrid_clock.cc:648] HybridClock initialized: now 1786515569099483 us; error 0 us; skew 500 ppm
I20260812 06:19:29.101428  5532 webserver.cc:533] Webserver started at http://127.5.103.62:34283/ using document root <none> and password file <none>
I20260812 06:19:29.101979  5532 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:29.102068  5532 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:29.102304  5532 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:29.104007  5532 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/master-0-root/instance:
uuid: "75d5106af95e44b3933368b4be21e770"
format_stamp: "Formatted at 2026-08-12 06:19:29 on dist-test-slave-w206"
I20260812 06:19:29.107635  5532 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:29.109710  5545 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:29.110788  5532 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:29.110940  5532 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/master-0-root
uuid: "75d5106af95e44b3933368b4be21e770"
format_stamp: "Formatted at 2026-08-12 06:19:29 on dist-test-slave-w206"
I20260812 06:19:29.111104  5532 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-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:29.129282  5532 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:29.129951  5532 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:29.130141  5532 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:29.137885  5532 rpc_server.cc:307] RPC server started. Bound to: 127.5.103.62:36123
I20260812 06:19:29.137941  5601 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.103.62:36123 every 8 connection(s)
I20260812 06:19:29.140336  5602 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:29.145896  5602 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770: Bootstrap starting.
I20260812 06:19:29.148324  5602 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:29.149309  5602 log.cc:826] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:29.151232  5602 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770: No bootstrap required, opened a new log
I20260812 06:19:29.154093  5602 raft_consensus.cc:359] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "75d5106af95e44b3933368b4be21e770" member_type: VOTER }
I20260812 06:19:29.154275  5602 raft_consensus.cc:385] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:29.154357  5602 raft_consensus.cc:740] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 75d5106af95e44b3933368b4be21e770, State: Initialized, Role: FOLLOWER
I20260812 06:19:29.155015  5602 consensus_queue.cc:260] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [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: "75d5106af95e44b3933368b4be21e770" member_type: VOTER }
I20260812 06:19:29.155185  5602 raft_consensus.cc:399] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:29.155272  5602 raft_consensus.cc:493] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:29.155409  5602 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:29.156251  5602 raft_consensus.cc:515] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "75d5106af95e44b3933368b4be21e770" member_type: VOTER }
I20260812 06:19:29.156709  5602 leader_election.cc:304] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [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: 75d5106af95e44b3933368b4be21e770; no voters: 
I20260812 06:19:29.157043  5602 leader_election.cc:290] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:29.157290  5605 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:29.157583  5605 raft_consensus.cc:697] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [term 1 LEADER]: Becoming Leader. State: Replica: 75d5106af95e44b3933368b4be21e770, State: Running, Role: LEADER
I20260812 06:19:29.158041  5605 consensus_queue.cc:237] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [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: "75d5106af95e44b3933368b4be21e770" member_type: VOTER }
I20260812 06:19:29.158136  5602 sys_catalog.cc:565] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:29.160501  5532 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:29.160502  5607 sys_catalog.cc:455] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 75d5106af95e44b3933368b4be21e770. Latest consensus state: current_term: 1 leader_uuid: "75d5106af95e44b3933368b4be21e770" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "75d5106af95e44b3933368b4be21e770" member_type: VOTER } }
I20260812 06:19:29.160696  5607 sys_catalog.cc:458] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:29.160516  5606 sys_catalog.cc:455] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "75d5106af95e44b3933368b4be21e770" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "75d5106af95e44b3933368b4be21e770" member_type: VOTER } }
I20260812 06:19:29.160991  5606 sys_catalog.cc:458] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [sys.catalog]: This master's current role is: LEADER
W20260812 06:19:29.162957  5619 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:29.163125  5619 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:29.163194  5620 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:29.163992  5620 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:29.169276  5620 catalog_manager.cc:1383] Generated new cluster ID: 15b42a52643343bb86881e002e6664b3
I20260812 06:19:29.169364  5620 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:29.191107  5620 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:29.192396  5620 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:29.202726  5620 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770: Generated new TSK 0
I20260812 06:19:29.203563  5620 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:29.225762  5532 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:29.229120  5626 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:29.229314  5628 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:29.229389  5625 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:29.229488  5532 server_base.cc:1061] running on GCE node
I20260812 06:19:29.229696  5532 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:29.229743  5532 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:29.229763  5532 hybrid_clock.cc:648] HybridClock initialized: now 1786515569229762 us; error 0 us; skew 500 ppm
I20260812 06:19:29.230873  5532 webserver.cc:533] Webserver started at http://127.5.103.1:38933/ using document root <none> and password file <none>
I20260812 06:19:29.231108  5532 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:29.231179  5532 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:29.231274  5532 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:29.231750  5532 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/instance:
uuid: "4c9ae7c408424dc79e6e43235a93fc92"
format_stamp: "Formatted at 2026-08-12 06:19:29 on dist-test-slave-w206"
I20260812 06:19:29.233449  5532 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:29.234552  5634 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:29.234835  5532 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:29.234936  5532 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root
uuid: "4c9ae7c408424dc79e6e43235a93fc92"
format_stamp: "Formatted at 2026-08-12 06:19:29 on dist-test-slave-w206"
I20260812 06:19:29.235041  5532 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-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:29.246452  5532 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:29.247049  5532 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:29.247624  5532 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:29.248512  5532 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:29.248567  5532 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:29.248644  5532 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:29.248698  5532 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:29.256384  5532 rpc_server.cc:307] RPC server started. Bound to: 127.5.103.1:41121
I20260812 06:19:29.256423  5706 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.103.1:41121 every 8 connection(s)
I20260812 06:19:29.267062  5707 heartbeater.cc:344] Connected to a master server at 127.5.103.62:36123
I20260812 06:19:29.267349  5707 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:29.267807  5707 heartbeater.cc:507] Master 127.5.103.62:36123 requested a full tablet report, sending...
I20260812 06:19:29.269228  5564 ts_manager.cc:194] Registered new tserver with Master: 4c9ae7c408424dc79e6e43235a93fc92 (127.5.103.1:41121)
I20260812 06:19:29.269426  5532 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012350451s
I20260812 06:19:29.270803  5564 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50930
I20260812 06:19:29.278847  5564 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50946:
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:29.293510  5666 tablet_service.cc:1511] Processing CreateTablet for tablet e5cbd7bcbc3e4dd8addc9ce4b83f105c (DEFAULT_TABLE table=heavy-update-compaction-test [id=e8cb0c6dd8484210aebf897f21695324]), partition=
I20260812 06:19:29.294073  5666 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e5cbd7bcbc3e4dd8addc9ce4b83f105c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:29.296979  5721 tablet_bootstrap.cc:492] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Bootstrap starting.
I20260812 06:19:29.298061  5721 tablet_bootstrap.cc:654] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:29.299409  5721 tablet_bootstrap.cc:492] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: No bootstrap required, opened a new log
I20260812 06:19:29.299516  5721 ts_tablet_manager.cc:1403] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:29.300037  5721 raft_consensus.cc:359] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c9ae7c408424dc79e6e43235a93fc92" member_type: VOTER last_known_addr { host: "127.5.103.1" port: 41121 } }
I20260812 06:19:29.300175  5721 raft_consensus.cc:385] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:29.300211  5721 raft_consensus.cc:740] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4c9ae7c408424dc79e6e43235a93fc92, State: Initialized, Role: FOLLOWER
I20260812 06:19:29.300381  5721 consensus_queue.cc:260] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92 [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: "4c9ae7c408424dc79e6e43235a93fc92" member_type: VOTER last_known_addr { host: "127.5.103.1" port: 41121 } }
I20260812 06:19:29.300477  5721 raft_consensus.cc:399] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:29.300515  5721 raft_consensus.cc:493] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:29.300565  5721 raft_consensus.cc:3060] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:29.301491  5721 raft_consensus.cc:515] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c9ae7c408424dc79e6e43235a93fc92" member_type: VOTER last_known_addr { host: "127.5.103.1" port: 41121 } }
I20260812 06:19:29.301636  5721 leader_election.cc:304] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92 [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: 4c9ae7c408424dc79e6e43235a93fc92; no voters: 
I20260812 06:19:29.301846  5721 leader_election.cc:290] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:29.302132  5724 raft_consensus.cc:2804] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:29.302181  5721 ts_tablet_manager.cc:1434] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:29.302371  5724 raft_consensus.cc:697] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92 [term 1 LEADER]: Becoming Leader. State: Replica: 4c9ae7c408424dc79e6e43235a93fc92, State: Running, Role: LEADER
I20260812 06:19:29.302583  5707 heartbeater.cc:499] Master 127.5.103.62:36123 was elected leader, sending a full tablet report...
I20260812 06:19:29.302577  5724 consensus_queue.cc:237] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92 [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: "4c9ae7c408424dc79e6e43235a93fc92" member_type: VOTER last_known_addr { host: "127.5.103.1" port: 41121 } }
I20260812 06:19:29.305580  5564 catalog_manager.cc:5719] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92 reported cstate change: term changed from 0 to 1, leader changed from <none> to 4c9ae7c408424dc79e6e43235a93fc92 (127.5.103.1). New cstate: current_term: 1 leader_uuid: "4c9ae7c408424dc79e6e43235a93fc92" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c9ae7c408424dc79e6e43235a93fc92" member_type: VOTER last_known_addr { host: "127.5.103.1" port: 41121 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:29.370167  5532 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.022s	sys 0.004s
I20260812 06:19:29.507536  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushMRSOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=19.054940
I20260812 06:19:29.655906  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushMRSOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.148s	user 0.113s	sys 0.033s Metrics: {"bytes_written":9558873,"cfile_init":1,"compiler_manager_pool.queue_time_us":187,"delete_count":0,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":879,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37024,"lbm_writes_lt_1ms":690,"mutex_wait_us":198,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":158464,"thread_start_us":122,"threads_started":1,"update_count":1165}
I20260812 06:19:29.657472  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling LogGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): free 20743831 bytes of WAL
I20260812 06:19:29.657970  5639 log_reader.cc:385] T e5cbd7bcbc3e4dd8addc9ce4b83f105c: removed 2 log segments from log reader
I20260812 06:19:29.658047  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000001 (ops 1-6)
I20260812 06:19:29.658113  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000002 (ops 7-11)
I20260812 06:19:29.664631  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: LogGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.007s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:19:29.665096  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.196750
I20260812 06:19:29.692169  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.027s	user 0.009s	sys 0.001s Metrics: {"bytes_written":2748830,"delete_count":0,"lbm_write_time_us":4071,"lbm_writes_lt_1ms":70,"reinsert_count":0,"update_count":335}
I20260812 06:19:29.692668  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:29.703390  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4369,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.703765  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:29.864522  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.161s	user 0.121s	sys 0.028s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672362,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":776,"lbm_read_time_us":9466,"lbm_reads_lt_1ms":473,"lbm_write_time_us":30513,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":358,"threads_started":5,"update_count":2000}
I20260812 06:19:29.865123  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=10.126437
I20260812 06:19:29.918639  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.053s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21326,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.919236  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:29.933897  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5546,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.934425  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling UndoDeltaBlockGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): 16411392 bytes on disk
I20260812 06:19:29.935022  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: UndoDeltaBlockGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:19:29.935475  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:30.064610  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.129s	user 0.085s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":170,"lbm_read_time_us":8012,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26972,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2000}
I20260812 06:19:30.065143  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=10.126437
I20260812 06:19:30.113206  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.048s	user 0.029s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18737,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:30.113652  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:30.125456  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4484,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.126082  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:30.265107  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.139s	user 0.105s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":282,"lbm_read_time_us":9865,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26777,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.265733  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=10.126437
I20260812 06:19:30.312705  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.047s	user 0.018s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16709,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:30.313243  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:30.323998  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4047,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.324478  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:30.477921  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.153s	user 0.105s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":576,"lbm_read_time_us":10913,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25664,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.478801  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=11.118625
I20260812 06:19:30.519703  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.041s	user 0.020s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15940,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:30.520153  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:30.536842  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.017s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4116,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.537369  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:30.547190  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3715,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:30.547703  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:30.709569  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.162s	user 0.118s	sys 0.031s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1290,"lbm_read_time_us":10878,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29724,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":83072,"update_count":2500}
I20260812 06:19:30.710047  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=14.095187
I20260812 06:19:30.766373  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.056s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22637,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.766913  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:30.781930  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5540,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.782543  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:30.937752  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.155s	user 0.115s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1312,"lbm_read_time_us":9364,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30759,"lbm_writes_lt_1ms":543,"mutex_wait_us":354,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:19:30.938519  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=14.095187
I20260812 06:19:30.986745  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.048s	user 0.007s	sys 0.035s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20526,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.987262  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:31.002461  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.015s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5582,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.003221  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushMRSOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:31.034515  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushMRSOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":1325,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1842,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:31.035341  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling LogGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): free 124710344 bytes of WAL
I20260812 06:19:31.035563  5639 log_reader.cc:385] T e5cbd7bcbc3e4dd8addc9ce4b83f105c: removed 12 log segments from log reader
I20260812 06:19:31.035609  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000003 (ops 12-16)
I20260812 06:19:31.035635  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000004 (ops 17-21)
I20260812 06:19:31.035699  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000005 (ops 22-26)
I20260812 06:19:31.035742  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000006 (ops 27-31)
I20260812 06:19:31.035781  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000007 (ops 32-36)
I20260812 06:19:31.035810  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000008 (ops 37-41)
I20260812 06:19:31.035861  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000009 (ops 42-46)
I20260812 06:19:31.035912  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000010 (ops 47-51)
I20260812 06:19:31.035945  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000011 (ops 52-56)
I20260812 06:19:31.035987  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000012 (ops 57-61)
I20260812 06:19:31.036028  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000013 (ops 62-66)
I20260812 06:19:31.036067  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000014 (ops 67-71)
I20260812 06:19:31.066043  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: LogGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:31.066697  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling UndoDeltaBlockGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): 480 bytes on disk
I20260812 06:19:31.067286  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: UndoDeltaBlockGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:19:31.067734  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=3.181125
I20260812 06:19:31.082141  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":5046218,"delete_count":0,"lbm_write_time_us":6056,"lbm_writes_lt_1ms":126,"reinsert_count":0,"update_count":615}
I20260812 06:19:31.082578  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.196750
I20260812 06:19:31.092096  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.009s	user 0.001s	sys 0.007s Metrics: {"bytes_written":3159080,"delete_count":0,"lbm_write_time_us":3416,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:19:31.092561  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:31.308981  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.216s	user 0.126s	sys 0.085s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979732,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":724,"lbm_read_time_us":13213,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38387,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:19:31.309746  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=14.095187
I20260812 06:19:31.375881  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.066s	user 0.034s	sys 0.031s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27938,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.376333  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=3.181125
I20260812 06:19:31.403504  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.027s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6572,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:31.404013  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:31.413653  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3876,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:31.414281  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:31.626482  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.212s	user 0.130s	sys 0.081s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877208,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":778,"lbm_read_time_us":12784,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36749,"lbm_writes_lt_1ms":643,"mutex_wait_us":332,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:19:31.627352  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=14.095187
I20260812 06:19:31.677100  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.049s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22286,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.677663  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:31.694751  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6735,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.695217  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:31.882299  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.187s	user 0.143s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":298,"lbm_read_time_us":12841,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33832,"lbm_writes_lt_1ms":543,"mutex_wait_us":87,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:31.882887  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=14.095187
I20260812 06:19:31.958606  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.074s	user 0.036s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":30402,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.959448  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:31.970772  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3958,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.971398  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:32.158318  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.187s	user 0.120s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":259,"lbm_read_time_us":13544,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29977,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:32.159390  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=14.095187
I20260812 06:19:32.221479  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.062s	user 0.030s	sys 0.029s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22385,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.222150  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:32.239831  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6382,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.240576  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:32.436144  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.195s	user 0.123s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1807,"lbm_read_time_us":13702,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32935,"lbm_writes_lt_1ms":543,"mutex_wait_us":1416,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:19:32.437407  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=14.095187
I20260812 06:19:32.488673  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.051s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21350,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.489202  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:32.510067  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.021s	user 0.006s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4180,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.510643  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushMRSOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:32.550010  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushMRSOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.039s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1358,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1648,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:32.550745  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling LogGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): free 120553340 bytes of WAL
I20260812 06:19:32.551057  5639 log_reader.cc:385] T e5cbd7bcbc3e4dd8addc9ce4b83f105c: removed 12 log segments from log reader
I20260812 06:19:32.551103  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000015 (ops 72-76)
I20260812 06:19:32.551136  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000016 (ops 77-81)
I20260812 06:19:32.551195  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000017 (ops 82-86)
I20260812 06:19:32.551239  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000018 (ops 87-91)
I20260812 06:19:32.551278  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000019 (ops 92-96)
I20260812 06:19:32.551338  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000020 (ops 97-100)
I20260812 06:19:32.551391  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000021 (ops 101-105)
I20260812 06:19:32.551422  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000022 (ops 106-110)
I20260812 06:19:32.551456  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000023 (ops 111-115)
I20260812 06:19:32.551496  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000024 (ops 116-120)
I20260812 06:19:32.551584  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000025 (ops 121-124)
I20260812 06:19:32.551625  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000026 (ops 125-129)
I20260812 06:19:32.579101  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: LogGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.028s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:19:32.580456  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=3.181125
I20260812 06:19:32.595556  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.015s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4266756,"delete_count":0,"lbm_write_time_us":4664,"lbm_writes_lt_1ms":107,"reinsert_count":0,"update_count":520}
I20260812 06:19:32.596095  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:32.606730  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":4227,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:19:32.607276  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling UndoDeltaBlockGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): 448 bytes on disk
I20260812 06:19:32.607811  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: UndoDeltaBlockGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:19:32.608695  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:32.878382  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.269s	user 0.154s	sys 0.103s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979748,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1320,"lbm_read_time_us":17752,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41971,"lbm_writes_lt_1ms":743,"mutex_wait_us":640,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12800,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:19:32.879096  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=18.063937
I20260812 06:19:32.952107  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.073s	user 0.041s	sys 0.020s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28125,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:32.952708  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:32.964435  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4150,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.964941  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:33.174968  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.210s	user 0.129s	sys 0.080s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":799,"lbm_read_time_us":12613,"lbm_reads_lt_1ms":672,"lbm_write_time_us":38286,"lbm_writes_lt_1ms":643,"mutex_wait_us":319,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:33.176649  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=15.087375
I20260812 06:19:33.226732  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.050s	user 0.038s	sys 0.006s Metrics: {"bytes_written":16656047,"delete_count":0,"lbm_write_time_us":21090,"lbm_writes_lt_1ms":409,"reinsert_count":0,"update_count":2030}
I20260812 06:19:33.227488  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:33.251050  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.023s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":5096,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:19:33.251511  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:33.263266  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4720,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.264037  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:33.466130  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.202s	user 0.113s	sys 0.088s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877215,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":839,"lbm_read_time_us":14173,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34305,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":3000}
I20260812 06:19:33.466879  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=15.087375
I20260812 06:19:33.514400  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.047s	user 0.033s	sys 0.010s Metrics: {"bytes_written":16779169,"delete_count":0,"lbm_write_time_us":21086,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2045}
I20260812 06:19:33.514935  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:33.535444  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.020s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":5643,"lbm_writes_lt_1ms":94,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":455}
I20260812 06:19:33.535938  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:33.546900  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4405,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.547411  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:33.747462  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.200s	user 0.131s	sys 0.068s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877262,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":534,"lbm_read_time_us":12812,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36550,"lbm_writes_lt_1ms":643,"mutex_wait_us":4,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":3000}
I20260812 06:19:33.748162  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=14.095187
I20260812 06:19:33.807020  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.059s	user 0.038s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":26775,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.807933  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:33.825687  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.018s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5626,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:19:33.826161  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:34.004108  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.178s	user 0.124s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1091,"lbm_read_time_us":12708,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31401,"lbm_writes_lt_1ms":543,"mutex_wait_us":308,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2500}
I20260812 06:19:34.004786  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=14.095187
I20260812 06:19:34.067421  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.062s	user 0.028s	sys 0.032s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27660,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.067998  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:34.082176  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.014s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5244,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.082777  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushMRSOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:34.138106  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushMRSOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.055s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":190,"dirs.run_wall_time_us":1258,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2609,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31,"spinlock_wait_cycles":17792}
I20260812 06:19:34.138863  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling LogGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): free 121006766 bytes of WAL
I20260812 06:19:34.139154  5639 log_reader.cc:385] T e5cbd7bcbc3e4dd8addc9ce4b83f105c: removed 12 log segments from log reader
I20260812 06:19:34.139225  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000027 (ops 130-134)
I20260812 06:19:34.139266  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000028 (ops 135-139)
I20260812 06:19:34.139292  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000029 (ops 140-144)
I20260812 06:19:34.139314  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000030 (ops 145-148)
I20260812 06:19:34.139335  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000031 (ops 149-153)
I20260812 06:19:34.139358  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000032 (ops 154-158)
I20260812 06:19:34.139380  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000033 (ops 159-163)
I20260812 06:19:34.139405  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000034 (ops 164-168)
I20260812 06:19:34.139441  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000035 (ops 169-173)
I20260812 06:19:34.139467  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000036 (ops 174-178)
I20260812 06:19:34.139487  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000037 (ops 179-183)
I20260812 06:19:34.139509  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000038 (ops 184-188)
I20260812 06:19:34.171443  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: LogGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.032s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:19:34.171890  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling UndoDeltaBlockGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): 482 bytes on disk
I20260812 06:19:34.172350  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: UndoDeltaBlockGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:34.172920  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=6.157687
I20260812 06:19:34.196749  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.024s	user 0.010s	sys 0.009s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8746,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:34.197269  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling LogGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): free 11564893 bytes of WAL
I20260812 06:19:34.197484  5639 log_reader.cc:385] T e5cbd7bcbc3e4dd8addc9ce4b83f105c: removed 1 log segments from log reader
I20260812 06:19:34.197525  5639 log.cc:1079] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/e5cbd7bcbc3e4dd8addc9ce4b83f105c/wal-000000039 (ops 189-192)
I20260812 06:19:34.199934  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: LogGCOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:34.200250  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=2.188937
I20260812 06:19:34.212507  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4750,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.212984  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=1.000000
I20260812 06:19:34.382541  5532 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.012s	user 1.810s	sys 0.166s
I20260812 06:19:34.453999  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: MajorDeltaCompactionOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.241s	user 0.155s	sys 0.083s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082165,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":17879,"lbm_reads_lt_1ms":870,"lbm_write_time_us":47887,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"update_count":4000}
I20260812 06:19:34.454488  5709 maintenance_manager.cc:419] P 4c9ae7c408424dc79e6e43235a93fc92: Scheduling FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c): perf score=14.095187
I20260812 06:19:34.490401  5532 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.107s	user 0.002s	sys 0.000s
I20260812 06:19:34.491230  5532 tablet_server.cc:179] TabletServer@127.5.103.1:0 shutting down...
I20260812 06:19:34.497133  5639 maintenance_manager.cc:643] P 4c9ae7c408424dc79e6e43235a93fc92: FlushDeltaMemStoresOp(e5cbd7bcbc3e4dd8addc9ce4b83f105c) complete. Timing: real 0.042s	user 0.033s	sys 0.006s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17565,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.497649  5532 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:34.498060  5532 tablet_replica.cc:333] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92: stopping tablet replica
I20260812 06:19:34.498260  5532 raft_consensus.cc:2243] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:34.498441  5532 raft_consensus.cc:2272] T e5cbd7bcbc3e4dd8addc9ce4b83f105c P 4c9ae7c408424dc79e6e43235a93fc92 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:34.515481  5532 tablet_server.cc:196] TabletServer@127.5.103.1:0 shutdown complete.
I20260812 06:19:34.538054  5532 master.cc:562] Master@127.5.103.62:36123 shutting down...
I20260812 06:19:34.541603  5532 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:34.541759  5532 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:34.541811  5532 tablet_replica.cc:333] T 00000000000000000000000000000000 P 75d5106af95e44b3933368b4be21e770: stopping tablet replica
I20260812 06:19:34.554152  5532 master.cc:584] Master@127.5.103.62:36123 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5553 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:34.644021  5532 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.103.62:34027
I20260812 06:19:34.644443  5532 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:34.646777  5742 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:34.646859  5532 server_base.cc:1061] running on GCE node
W20260812 06:19:34.646912  5743 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:34.647053  5745 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:34.647265  5532 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:34.647362  5532 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:34.647413  5532 hybrid_clock.cc:648] HybridClock initialized: now 1786515574647412 us; error 0 us; skew 500 ppm
I20260812 06:19:34.648290  5532 webserver.cc:533] Webserver started at http://127.5.103.62:44067/ using document root <none> and password file <none>
I20260812 06:19:34.648474  5532 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:34.648540  5532 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:34.648625  5532 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:34.648994  5532 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/master-0-root/instance:
uuid: "df83358b207b402b9d247560d1ce57bb"
format_stamp: "Formatted at 2026-08-12 06:19:34 on dist-test-slave-w206"
I20260812 06:19:34.650480  5532 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:34.651424  5751 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:34.651679  5532 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:19:34.651744  5532 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/master-0-root
uuid: "df83358b207b402b9d247560d1ce57bb"
format_stamp: "Formatted at 2026-08-12 06:19:34 on dist-test-slave-w206"
I20260812 06:19:34.651839  5532 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-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:34.668475  5532 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:34.668872  5532 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:34.673192  5532 rpc_server.cc:307] RPC server started. Bound to: 127.5.103.62:34027
I20260812 06:19:34.674568  5809 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.103.62:34027 every 8 connection(s)
I20260812 06:19:34.674700  5810 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:34.692302  5810 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb: Bootstrap starting.
I20260812 06:19:34.693217  5810 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:34.694336  5810 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb: No bootstrap required, opened a new log
I20260812 06:19:34.694748  5810 raft_consensus.cc:359] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "df83358b207b402b9d247560d1ce57bb" member_type: VOTER }
I20260812 06:19:34.694859  5810 raft_consensus.cc:385] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:34.694919  5810 raft_consensus.cc:740] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: df83358b207b402b9d247560d1ce57bb, State: Initialized, Role: FOLLOWER
I20260812 06:19:34.695114  5810 consensus_queue.cc:260] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [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: "df83358b207b402b9d247560d1ce57bb" member_type: VOTER }
I20260812 06:19:34.695210  5810 raft_consensus.cc:399] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:34.695261  5810 raft_consensus.cc:493] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:34.695327  5810 raft_consensus.cc:3060] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:34.696070  5810 raft_consensus.cc:515] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "df83358b207b402b9d247560d1ce57bb" member_type: VOTER }
I20260812 06:19:34.696216  5810 leader_election.cc:304] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [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: df83358b207b402b9d247560d1ce57bb; no voters: 
I20260812 06:19:34.696424  5810 leader_election.cc:290] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:34.696556  5813 raft_consensus.cc:2804] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:34.696774  5813 raft_consensus.cc:697] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [term 1 LEADER]: Becoming Leader. State: Replica: df83358b207b402b9d247560d1ce57bb, State: Running, Role: LEADER
I20260812 06:19:34.696877  5810 sys_catalog.cc:565] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:34.696935  5813 consensus_queue.cc:237] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [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: "df83358b207b402b9d247560d1ce57bb" member_type: VOTER }
I20260812 06:19:34.697402  5814 sys_catalog.cc:455] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "df83358b207b402b9d247560d1ce57bb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "df83358b207b402b9d247560d1ce57bb" member_type: VOTER } }
I20260812 06:19:34.697435  5815 sys_catalog.cc:455] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [sys.catalog]: SysCatalogTable state changed. Reason: New leader df83358b207b402b9d247560d1ce57bb. Latest consensus state: current_term: 1 leader_uuid: "df83358b207b402b9d247560d1ce57bb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "df83358b207b402b9d247560d1ce57bb" member_type: VOTER } }
I20260812 06:19:34.697494  5814 sys_catalog.cc:458] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:34.697520  5815 sys_catalog.cc:458] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:34.698725  5532 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:19:34.699189  5830 catalog_manager.cc:1594] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:34.699245  5830 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:34.699337  5819 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:34.699959  5819 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:34.701663  5819 catalog_manager.cc:1383] Generated new cluster ID: be7558a57d164890b921be991427744c
I20260812 06:19:34.701725  5819 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:34.720661  5819 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:34.721244  5819 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:34.731547  5819 catalog_manager.cc:6092] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb: Generated new TSK 0
I20260812 06:19:34.731747  5819 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:34.763628  5532 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:34.765755  5832 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:34.765810  5835 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:34.765848  5833 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:34.765863  5532 server_base.cc:1061] running on GCE node
I20260812 06:19:34.766139  5532 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:34.766206  5532 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:34.766232  5532 hybrid_clock.cc:648] HybridClock initialized: now 1786515574766231 us; error 0 us; skew 500 ppm
I20260812 06:19:34.767130  5532 webserver.cc:533] Webserver started at http://127.5.103.1:37303/ using document root <none> and password file <none>
I20260812 06:19:34.767304  5532 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:34.767377  5532 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:34.767462  5532 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:34.767884  5532 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/instance:
uuid: "d699da5c3c7840c6af5bd1e6928a487c"
format_stamp: "Formatted at 2026-08-12 06:19:34 on dist-test-slave-w206"
I20260812 06:19:34.769368  5532 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:34.770251  5840 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:34.770500  5532 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:34.770588  5532 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root
uuid: "d699da5c3c7840c6af5bd1e6928a487c"
format_stamp: "Formatted at 2026-08-12 06:19:34 on dist-test-slave-w206"
I20260812 06:19:34.770673  5532 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-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:34.783555  5532 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:34.783947  5532 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:34.784255  5532 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:34.784720  5532 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:34.784780  5532 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:34.784844  5532 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:34.784902  5532 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:34.789273  5532 rpc_server.cc:307] RPC server started. Bound to: 127.5.103.1:34873
I20260812 06:19:34.789311  5913 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.103.1:34873 every 8 connection(s)
I20260812 06:19:34.797895  5914 heartbeater.cc:344] Connected to a master server at 127.5.103.62:34027
I20260812 06:19:34.798039  5914 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:34.798270  5914 heartbeater.cc:507] Master 127.5.103.62:34027 requested a full tablet report, sending...
I20260812 06:19:34.798943  5770 ts_manager.cc:194] Registered new tserver with Master: d699da5c3c7840c6af5bd1e6928a487c (127.5.103.1:34873)
I20260812 06:19:34.799619  5532 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009897629s
I20260812 06:19:34.799705  5770 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48420
I20260812 06:19:34.806478  5770 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48436:
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:34.814836  5871 tablet_service.cc:1511] Processing CreateTablet for tablet 0a0264520d62452d84d2c5c3d39fb359 (DEFAULT_TABLE table=heavy-update-compaction-test [id=1653f3284d84458f920aaf5a74b9f292]), partition=
I20260812 06:19:34.815140  5871 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 0a0264520d62452d84d2c5c3d39fb359. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:34.817097  5926 tablet_bootstrap.cc:492] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Bootstrap starting.
I20260812 06:19:34.817957  5926 tablet_bootstrap.cc:654] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:34.818955  5926 tablet_bootstrap.cc:492] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: No bootstrap required, opened a new log
I20260812 06:19:34.819100  5926 ts_tablet_manager.cc:1403] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:34.819516  5926 raft_consensus.cc:359] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d699da5c3c7840c6af5bd1e6928a487c" member_type: VOTER last_known_addr { host: "127.5.103.1" port: 34873 } }
I20260812 06:19:34.819602  5926 raft_consensus.cc:385] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:34.819659  5926 raft_consensus.cc:740] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d699da5c3c7840c6af5bd1e6928a487c, State: Initialized, Role: FOLLOWER
I20260812 06:19:34.819834  5926 consensus_queue.cc:260] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c [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: "d699da5c3c7840c6af5bd1e6928a487c" member_type: VOTER last_known_addr { host: "127.5.103.1" port: 34873 } }
I20260812 06:19:34.819972  5926 raft_consensus.cc:399] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:34.820029  5926 raft_consensus.cc:493] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:34.820093  5926 raft_consensus.cc:3060] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:34.820909  5926 raft_consensus.cc:515] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d699da5c3c7840c6af5bd1e6928a487c" member_type: VOTER last_known_addr { host: "127.5.103.1" port: 34873 } }
I20260812 06:19:34.821062  5926 leader_election.cc:304] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c [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: d699da5c3c7840c6af5bd1e6928a487c; no voters: 
I20260812 06:19:34.821274  5926 leader_election.cc:290] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:34.821413  5929 raft_consensus.cc:2804] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:34.821619  5926 ts_tablet_manager.cc:1434] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:34.821643  5929 raft_consensus.cc:697] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c [term 1 LEADER]: Becoming Leader. State: Replica: d699da5c3c7840c6af5bd1e6928a487c, State: Running, Role: LEADER
I20260812 06:19:34.821648  5914 heartbeater.cc:499] Master 127.5.103.62:34027 was elected leader, sending a full tablet report...
I20260812 06:19:34.821803  5929 consensus_queue.cc:237] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c [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: "d699da5c3c7840c6af5bd1e6928a487c" member_type: VOTER last_known_addr { host: "127.5.103.1" port: 34873 } }
I20260812 06:19:34.823141  5770 catalog_manager.cc:5719] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c reported cstate change: term changed from 0 to 1, leader changed from <none> to d699da5c3c7840c6af5bd1e6928a487c (127.5.103.1). New cstate: current_term: 1 leader_uuid: "d699da5c3c7840c6af5bd1e6928a487c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d699da5c3c7840c6af5bd1e6928a487c" member_type: VOTER last_known_addr { host: "127.5.103.1" port: 34873 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:34.882874  5532 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.018s	sys 0.004s
I20260812 06:19:35.040373  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushMRSOp(0a0264520d62452d84d2c5c3d39fb359): perf score=19.054940
I20260812 06:19:35.211279  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushMRSOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.171s	user 0.122s	sys 0.048s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":983,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":47879,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:35.212044  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling LogGCOp(0a0264520d62452d84d2c5c3d39fb359): free 20743831 bytes of WAL
I20260812 06:19:35.212287  5846 log_reader.cc:385] T 0a0264520d62452d84d2c5c3d39fb359: removed 2 log segments from log reader
I20260812 06:19:35.212330  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000001 (ops 1-6)
I20260812 06:19:35.212383  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000002 (ops 7-11)
I20260812 06:19:35.217562  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: LogGCOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:35.217978  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling UndoDeltaBlockGCOp(0a0264520d62452d84d2c5c3d39fb359): 16411392 bytes on disk
I20260812 06:19:35.218436  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: UndoDeltaBlockGCOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:19:35.219025  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:35.235176  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.016s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5245,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.235752  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:35.372707  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.137s	user 0.088s	sys 0.046s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1045,"lbm_read_time_us":10601,"lbm_reads_lt_1ms":460,"lbm_write_time_us":23891,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":340,"threads_started":5,"update_count":2000}
I20260812 06:19:35.373420  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=14.095187
I20260812 06:19:35.423810  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.050s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23206,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.424351  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:35.439247  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5428,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.439704  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:35.595734  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.156s	user 0.128s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":777,"lbm_read_time_us":9889,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28449,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24832,"update_count":2500}
I20260812 06:19:35.596527  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=14.095187
I20260812 06:19:35.659895  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.063s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21976,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.660436  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:35.671195  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.671615  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:35.858476  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.187s	user 0.117s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":352,"lbm_read_time_us":12300,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34207,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:19:35.859244  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=14.095187
I20260812 06:19:35.919149  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.060s	user 0.039s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22942,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.919747  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:35.933251  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4591,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.933789  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:36.118323  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.184s	user 0.133s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":708,"lbm_read_time_us":13500,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29465,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:19:36.118919  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=14.095187
I20260812 06:19:36.184887  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.066s	user 0.035s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24585,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.185439  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:36.196038  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4034,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.196518  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:36.386935  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.190s	user 0.125s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":231,"lbm_read_time_us":13861,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30683,"lbm_writes_lt_1ms":543,"mutex_wait_us":81,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:19:36.387840  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=11.118625
I20260812 06:19:36.423375  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.035s	user 0.005s	sys 0.030s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":14692,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:36.423945  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:36.458791  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.035s	user 0.014s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6195,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:36.459502  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:36.476261  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.016s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6150,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.476919  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushMRSOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:36.519690  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushMRSOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.043s	user 0.030s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1402,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1532,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:36.520327  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling LogGCOp(0a0264520d62452d84d2c5c3d39fb359): free 112239359 bytes of WAL
I20260812 06:19:36.520565  5846 log_reader.cc:385] T 0a0264520d62452d84d2c5c3d39fb359: removed 11 log segments from log reader
I20260812 06:19:36.520607  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000003 (ops 12-16)
I20260812 06:19:36.520637  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000004 (ops 17-20)
I20260812 06:19:36.520689  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000005 (ops 21-25)
I20260812 06:19:36.520731  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000006 (ops 26-30)
I20260812 06:19:36.520761  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000007 (ops 31-35)
I20260812 06:19:36.520815  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000008 (ops 36-40)
I20260812 06:19:36.520843  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000009 (ops 41-45)
I20260812 06:19:36.520884  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000010 (ops 46-50)
I20260812 06:19:36.520920  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000011 (ops 51-55)
I20260812 06:19:36.520957  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000012 (ops 56-60)
I20260812 06:19:36.520994  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000013 (ops 61-65)
I20260812 06:19:36.546409  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: LogGCOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:36.546950  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling UndoDeltaBlockGCOp(0a0264520d62452d84d2c5c3d39fb359): 463 bytes on disk
I20260812 06:19:36.547464  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: UndoDeltaBlockGCOp(0a0264520d62452d84d2c5c3d39fb359) 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:36.547961  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=3.181125
I20260812 06:19:36.563899  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.016s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4922,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:36.564407  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:36.574683  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3973,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:36.575213  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:36.815737  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.240s	user 0.170s	sys 0.064s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979849,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":517,"lbm_read_time_us":17146,"lbm_reads_lt_1ms":775,"lbm_write_time_us":40069,"lbm_writes_lt_1ms":743,"mutex_wait_us":301,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14976,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:19:36.816453  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=18.063937
I20260812 06:19:36.875313  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.059s	user 0.050s	sys 0.008s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25773,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:36.875867  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:36.890897  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5780,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.891531  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:37.101877  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.210s	user 0.148s	sys 0.057s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":215,"lbm_read_time_us":13926,"lbm_reads_lt_1ms":664,"lbm_write_time_us":38069,"lbm_writes_lt_1ms":643,"mutex_wait_us":37,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16128,"update_count":3000}
I20260812 06:19:37.102545  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=18.063937
I20260812 06:19:37.157284  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.055s	user 0.045s	sys 0.007s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":23768,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:37.157850  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:37.175803  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.018s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5698,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.176414  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:37.341176  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.165s	user 0.127s	sys 0.037s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":192,"lbm_read_time_us":12817,"lbm_reads_lt_1ms":664,"lbm_write_time_us":35260,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":3000}
I20260812 06:19:37.342151  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=14.095187
I20260812 06:19:37.390439  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.048s	user 0.016s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21558,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:37.391067  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:37.405881  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6062,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.406517  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:37.572852  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.166s	user 0.096s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":190,"lbm_read_time_us":10313,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29519,"lbm_writes_lt_1ms":543,"mutex_wait_us":85,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:19:37.573483  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=14.095187
I20260812 06:19:37.624828  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.051s	user 0.013s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23238,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:37.625324  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:37.794229  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.169s	user 0.106s	sys 0.051s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":992,"lbm_read_time_us":11010,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27482,"lbm_writes_lt_1ms":443,"mutex_wait_us":292,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18304,"update_count":2000}
I20260812 06:19:37.795117  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=14.095187
I20260812 06:19:37.852095  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.057s	user 0.019s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26036,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:37.852722  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:37.864766  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4376,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.865290  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushMRSOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:37.902217  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushMRSOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.037s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":200,"dirs.run_wall_time_us":1389,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2178,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:37.902922  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling LogGCOp(0a0264520d62452d84d2c5c3d39fb359): free 120553331 bytes of WAL
I20260812 06:19:37.903165  5846 log_reader.cc:385] T 0a0264520d62452d84d2c5c3d39fb359: removed 12 log segments from log reader
I20260812 06:19:37.903230  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000014 (ops 66-70)
I20260812 06:19:37.903283  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000015 (ops 71-74)
I20260812 06:19:37.903334  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000016 (ops 75-79)
I20260812 06:19:37.903378  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000017 (ops 80-84)
I20260812 06:19:37.903414  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000018 (ops 85-89)
I20260812 06:19:37.903455  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000019 (ops 90-94)
I20260812 06:19:37.903496  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000020 (ops 95-99)
I20260812 06:19:37.903537  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000021 (ops 100-104)
I20260812 06:19:37.903575  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000022 (ops 105-109)
I20260812 06:19:37.903614  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000023 (ops 110-114)
I20260812 06:19:37.903654  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000024 (ops 115-118)
I20260812 06:19:37.903694  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000025 (ops 119-123)
I20260812 06:19:37.928896  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: LogGCOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.026s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:37.929303  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling UndoDeltaBlockGCOp(0a0264520d62452d84d2c5c3d39fb359): 447 bytes on disk
I20260812 06:19:37.929718  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: UndoDeltaBlockGCOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:37.930183  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:37.951748  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.021s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4658,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.952193  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:37.963814  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.011s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4728,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.964416  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:38.222025  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.257s	user 0.155s	sys 0.102s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":477,"lbm_read_time_us":16231,"lbm_reads_lt_1ms":774,"lbm_write_time_us":45110,"lbm_writes_lt_1ms":743,"mutex_wait_us":25,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":819584,"thread_start_us":85,"threads_started":1,"update_count":3500}
I20260812 06:19:38.222843  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=18.063937
I20260812 06:19:38.296653  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.074s	user 0.025s	sys 0.037s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":29080,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:38.297232  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:38.313354  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6042,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.313997  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:38.529690  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.216s	user 0.140s	sys 0.075s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":110,"lbm_read_time_us":16072,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35356,"lbm_writes_lt_1ms":643,"mutex_wait_us":57,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":3000}
I20260812 06:19:38.530474  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=14.095187
I20260812 06:19:38.580937  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.050s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16532977,"delete_count":0,"lbm_write_time_us":21938,"lbm_writes_lt_1ms":406,"mutex_wait_us":1188,"reinsert_count":0,"update_count":2015}
I20260812 06:19:38.581521  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:38.606096  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":5336,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:19:38.606549  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:38.617830  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4666,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.618281  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:38.822227  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.204s	user 0.142s	sys 0.061s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":814,"lbm_read_time_us":15383,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33808,"lbm_writes_lt_1ms":643,"mutex_wait_us":370,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":3000}
I20260812 06:19:38.822841  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=14.095187
I20260812 06:19:38.865854  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.043s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19609,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.866340  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:38.879859  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4869,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.880507  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:39.057312  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.177s	user 0.113s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":216,"lbm_read_time_us":12866,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29842,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:19:39.058023  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=14.095187
I20260812 06:19:39.112772  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.055s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20115,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.113413  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:39.130010  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6117,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.130594  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:39.305177  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.174s	user 0.110s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":850,"lbm_read_time_us":12078,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29646,"lbm_writes_lt_1ms":543,"mutex_wait_us":343,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:39.305760  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=14.095187
I20260812 06:19:39.362160  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.056s	user 0.039s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20915,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.362749  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:39.373870  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4203,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.374315  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushMRSOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:39.415074  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushMRSOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.041s	user 0.031s	sys 0.004s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1412,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1513,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:39.415930  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling LogGCOp(0a0264520d62452d84d2c5c3d39fb359): free 120553621 bytes of WAL
I20260812 06:19:39.416186  5846 log_reader.cc:385] T 0a0264520d62452d84d2c5c3d39fb359: removed 12 log segments from log reader
I20260812 06:19:39.416256  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000026 (ops 124-128)
I20260812 06:19:39.416308  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000027 (ops 129-133)
I20260812 06:19:39.416368  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000028 (ops 134-138)
I20260812 06:19:39.416406  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000029 (ops 139-143)
I20260812 06:19:39.416445  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000030 (ops 144-148)
I20260812 06:19:39.416486  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000031 (ops 149-153)
I20260812 06:19:39.416527  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000032 (ops 154-158)
I20260812 06:19:39.416564  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000033 (ops 159-162)
I20260812 06:19:39.416603  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000034 (ops 163-167)
I20260812 06:19:39.416639  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000035 (ops 168-172)
I20260812 06:19:39.416675  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000036 (ops 173-176)
I20260812 06:19:39.416715  5846 log.cc:1079] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: Deleting log segment in path: /tmp/dist-test-tasko3nENA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515569079801-5532-0/minicluster-data/ts-0-root/wals/0a0264520d62452d84d2c5c3d39fb359/wal-000000037 (ops 177-181)
I20260812 06:19:39.442529  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: LogGCOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:39.443039  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling UndoDeltaBlockGCOp(0a0264520d62452d84d2c5c3d39fb359): 462 bytes on disk
I20260812 06:19:39.443813  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: UndoDeltaBlockGCOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:19:39.444406  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=3.181125
I20260812 06:19:39.460098  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.016s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4414,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:39.460561  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:39.470893  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.010s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4064,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.471460  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:39.706875  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.235s	user 0.164s	sys 0.065s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979738,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":264,"lbm_read_time_us":13763,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43635,"lbm_writes_lt_1ms":743,"mutex_wait_us":71,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4608,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:19:39.708912  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=18.063937
I20260812 06:19:39.768107  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.059s	user 0.043s	sys 0.015s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26274,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:39.769145  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359): perf score=2.188937
I20260812 06:19:39.786365  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: FlushDeltaMemStoresOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6190,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.786855  5915 maintenance_manager.cc:419] P d699da5c3c7840c6af5bd1e6928a487c: Scheduling MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359): perf score=1.000000
I20260812 06:19:39.851877  5532 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.969s	user 1.824s	sys 0.185s
I20260812 06:19:39.909619  5532 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.057s	user 0.001s	sys 0.000s
I20260812 06:19:39.910148  5532 tablet_server.cc:179] TabletServer@127.5.103.1:0 shutting down...
I20260812 06:19:39.958194  5846 maintenance_manager.cc:643] P d699da5c3c7840c6af5bd1e6928a487c: MajorDeltaCompactionOp(0a0264520d62452d84d2c5c3d39fb359) complete. Timing: real 0.171s	user 0.114s	sys 0.056s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":532,"lbm_read_time_us":13243,"lbm_reads_lt_1ms":660,"lbm_write_time_us":29290,"lbm_writes_lt_1ms":643,"mutex_wait_us":122,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19840,"update_count":3000}
I20260812 06:19:39.959020  5532 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:39.959303  5532 tablet_replica.cc:333] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c: stopping tablet replica
I20260812 06:19:39.959442  5532 raft_consensus.cc:2243] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:39.959645  5532 raft_consensus.cc:2272] T 0a0264520d62452d84d2c5c3d39fb359 P d699da5c3c7840c6af5bd1e6928a487c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:39.975539  5532 tablet_server.cc:196] TabletServer@127.5.103.1:0 shutdown complete.
I20260812 06:19:40.011952  5532 master.cc:562] Master@127.5.103.62:34027 shutting down...
I20260812 06:19:40.015329  5532 raft_consensus.cc:2243] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:40.015528  5532 raft_consensus.cc:2272] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:40.015579  5532 tablet_replica.cc:333] T 00000000000000000000000000000000 P df83358b207b402b9d247560d1ce57bb: stopping tablet replica
I20260812 06:19:40.028203  5532 master.cc:584] Master@127.5.103.62:34027 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5479 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11033 ms total)

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