[==========] 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:54.833503 14147 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.208.254:34725
I20260812 06:19:54.834503 14147 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:54.835103 14147 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:54.841306 14152 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:54.841316 14153 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:54.841601 14147 server_base.cc:1061] running on GCE node
W20260812 06:19:54.841658 14155 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:54.842175 14147 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:54.842271 14147 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:54.842306 14147 hybrid_clock.cc:648] HybridClock initialized: now 1786515594842305 us; error 0 us; skew 500 ppm
I20260812 06:19:54.844169 14147 webserver.cc:533] Webserver started at http://127.13.208.254:37653/ using document root <none> and password file <none>
I20260812 06:19:54.844782 14147 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:54.844864 14147 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:54.845122 14147 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:54.848796 14147 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/master-0-root/instance:
uuid: "aacaf0bd8d4949e48a4dbb76f746688d"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-bxbt"
I20260812 06:19:54.853107 14147 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.002s	sys 0.003s
I20260812 06:19:54.855532 14160 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:54.856587 14147 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.001s
I20260812 06:19:54.856698 14147 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/master-0-root
uuid: "aacaf0bd8d4949e48a4dbb76f746688d"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-bxbt"
I20260812 06:19:54.856781 14147 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-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:54.878464 14147 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:54.879060 14147 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:54.879200 14147 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:54.886770 14147 rpc_server.cc:307] RPC server started. Bound to: 127.13.208.254:34725
I20260812 06:19:54.886776 14212 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.208.254:34725 every 8 connection(s)
I20260812 06:19:54.889109 14213 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:54.894364 14213 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d: Bootstrap starting.
I20260812 06:19:54.896660 14213 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:54.897533 14213 log.cc:826] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:54.899125 14213 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d: No bootstrap required, opened a new log
I20260812 06:19:54.901844 14213 raft_consensus.cc:359] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aacaf0bd8d4949e48a4dbb76f746688d" member_type: VOTER }
I20260812 06:19:54.902056 14213 raft_consensus.cc:385] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:54.902146 14213 raft_consensus.cc:740] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: aacaf0bd8d4949e48a4dbb76f746688d, State: Initialized, Role: FOLLOWER
I20260812 06:19:54.902781 14213 consensus_queue.cc:260] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [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: "aacaf0bd8d4949e48a4dbb76f746688d" member_type: VOTER }
I20260812 06:19:54.902966 14213 raft_consensus.cc:399] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:54.903049 14213 raft_consensus.cc:493] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:54.903172 14213 raft_consensus.cc:3060] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:54.904074 14213 raft_consensus.cc:515] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aacaf0bd8d4949e48a4dbb76f746688d" member_type: VOTER }
I20260812 06:19:54.904526 14213 leader_election.cc:304] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [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: aacaf0bd8d4949e48a4dbb76f746688d; no voters: 
I20260812 06:19:54.904843 14213 leader_election.cc:290] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:54.905000 14216 raft_consensus.cc:2804] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:54.905265 14216 raft_consensus.cc:697] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [term 1 LEADER]: Becoming Leader. State: Replica: aacaf0bd8d4949e48a4dbb76f746688d, State: Running, Role: LEADER
I20260812 06:19:54.905686 14216 consensus_queue.cc:237] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [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: "aacaf0bd8d4949e48a4dbb76f746688d" member_type: VOTER }
I20260812 06:19:54.905946 14213 sys_catalog.cc:565] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:54.908036 14217 sys_catalog.cc:455] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "aacaf0bd8d4949e48a4dbb76f746688d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aacaf0bd8d4949e48a4dbb76f746688d" member_type: VOTER } }
I20260812 06:19:54.908051 14218 sys_catalog.cc:455] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [sys.catalog]: SysCatalogTable state changed. Reason: New leader aacaf0bd8d4949e48a4dbb76f746688d. Latest consensus state: current_term: 1 leader_uuid: "aacaf0bd8d4949e48a4dbb76f746688d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aacaf0bd8d4949e48a4dbb76f746688d" member_type: VOTER } }
I20260812 06:19:54.908218 14218 sys_catalog.cc:458] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:54.908219 14217 sys_catalog.cc:458] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:54.908605 14225 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:54.911175 14225 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:54.911518 14147 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:54.916271 14225 catalog_manager.cc:1383] Generated new cluster ID: 6c6e9cae40804d5d9efe6410175109af
I20260812 06:19:54.916337 14225 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:54.922698 14225 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:54.923466 14225 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:54.928399 14225 catalog_manager.cc:6092] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d: Generated new TSK 0
I20260812 06:19:54.928952 14225 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:54.944059 14147 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:54.946547 14235 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:54.946657 14236 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:54.946775 14238 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:54.947039 14147 server_base.cc:1061] running on GCE node
I20260812 06:19:54.947233 14147 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:54.947281 14147 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:54.947309 14147 hybrid_clock.cc:648] HybridClock initialized: now 1786515594947308 us; error 0 us; skew 500 ppm
I20260812 06:19:54.948305 14147 webserver.cc:533] Webserver started at http://127.13.208.193:39935/ using document root <none> and password file <none>
I20260812 06:19:54.948477 14147 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:54.948547 14147 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:54.948627 14147 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:54.949028 14147 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/instance:
uuid: "e1fc0f0fd5fd436a8301fcf0cb17a06c"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-bxbt"
I20260812 06:19:54.950562 14147 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:54.951614 14243 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:54.951894 14147 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:54.951974 14147 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root
uuid: "e1fc0f0fd5fd436a8301fcf0cb17a06c"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-bxbt"
I20260812 06:19:54.952073 14147 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-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:54.965556 14147 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:54.966028 14147 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:54.966539 14147 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:54.967479 14147 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:54.967536 14147 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:54.967605 14147 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:54.967641 14147 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:54.974514 14147 rpc_server.cc:307] RPC server started. Bound to: 127.13.208.193:38087
I20260812 06:19:54.974550 14306 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.208.193:38087 every 8 connection(s)
I20260812 06:19:54.984372 14307 heartbeater.cc:344] Connected to a master server at 127.13.208.254:34725
I20260812 06:19:54.984624 14307 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:54.985030 14307 heartbeater.cc:507] Master 127.13.208.254:34725 requested a full tablet report, sending...
I20260812 06:19:54.986382 14177 ts_manager.cc:194] Registered new tserver with Master: e1fc0f0fd5fd436a8301fcf0cb17a06c (127.13.208.193:38087)
I20260812 06:19:54.986485 14147 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011348444s
I20260812 06:19:54.987557 14177 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41482
I20260812 06:19:54.996690 14177 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41490:
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:55.011525 14271 tablet_service.cc:1511] Processing CreateTablet for tablet 30a2e8bf8a824722aa3df842baf2696f (DEFAULT_TABLE table=heavy-update-compaction-test [id=6de256271d174652a6a4e2e1eb2742cc]), partition=
I20260812 06:19:55.012013 14271 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 30a2e8bf8a824722aa3df842baf2696f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:55.014637 14319 tablet_bootstrap.cc:492] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Bootstrap starting.
I20260812 06:19:55.015561 14319 tablet_bootstrap.cc:654] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:55.016644 14319 tablet_bootstrap.cc:492] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: No bootstrap required, opened a new log
I20260812 06:19:55.016762 14319 ts_tablet_manager.cc:1403] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:55.017168 14319 raft_consensus.cc:359] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e1fc0f0fd5fd436a8301fcf0cb17a06c" member_type: VOTER last_known_addr { host: "127.13.208.193" port: 38087 } }
I20260812 06:19:55.017292 14319 raft_consensus.cc:385] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:55.017359 14319 raft_consensus.cc:740] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e1fc0f0fd5fd436a8301fcf0cb17a06c, State: Initialized, Role: FOLLOWER
I20260812 06:19:55.017514 14319 consensus_queue.cc:260] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c [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: "e1fc0f0fd5fd436a8301fcf0cb17a06c" member_type: VOTER last_known_addr { host: "127.13.208.193" port: 38087 } }
I20260812 06:19:55.017627 14319 raft_consensus.cc:399] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:55.017678 14319 raft_consensus.cc:493] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:55.017731 14319 raft_consensus.cc:3060] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:55.018409 14319 raft_consensus.cc:515] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e1fc0f0fd5fd436a8301fcf0cb17a06c" member_type: VOTER last_known_addr { host: "127.13.208.193" port: 38087 } }
I20260812 06:19:55.018560 14319 leader_election.cc:304] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c [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: e1fc0f0fd5fd436a8301fcf0cb17a06c; no voters: 
I20260812 06:19:55.018798 14319 leader_election.cc:290] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:55.018886 14321 raft_consensus.cc:2804] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:55.019058 14321 raft_consensus.cc:697] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c [term 1 LEADER]: Becoming Leader. State: Replica: e1fc0f0fd5fd436a8301fcf0cb17a06c, State: Running, Role: LEADER
I20260812 06:19:55.019239 14321 consensus_queue.cc:237] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c [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: "e1fc0f0fd5fd436a8301fcf0cb17a06c" member_type: VOTER last_known_addr { host: "127.13.208.193" port: 38087 } }
I20260812 06:19:55.019392 14307 heartbeater.cc:499] Master 127.13.208.254:34725 was elected leader, sending a full tablet report...
I20260812 06:19:55.019232 14319 ts_tablet_manager.cc:1434] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:55.021629 14177 catalog_manager.cc:5719] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c reported cstate change: term changed from 0 to 1, leader changed from <none> to e1fc0f0fd5fd436a8301fcf0cb17a06c (127.13.208.193). New cstate: current_term: 1 leader_uuid: "e1fc0f0fd5fd436a8301fcf0cb17a06c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e1fc0f0fd5fd436a8301fcf0cb17a06c" member_type: VOTER last_known_addr { host: "127.13.208.193" port: 38087 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:55.093832 14147 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.062s	user 0.024s	sys 0.008s
I20260812 06:19:55.225718 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushMRSOp(30a2e8bf8a824722aa3df842baf2696f): perf score=17.070565
I20260812 06:19:55.378859 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushMRSOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.153s	user 0.117s	sys 0.032s Metrics: {"bytes_written":9148636,"cfile_init":1,"compiler_manager_pool.queue_time_us":239,"delete_count":0,"dirs.queue_time_us":39,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":771,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36125,"lbm_writes_lt_1ms":680,"mutex_wait_us":162,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":81792,"thread_start_us":131,"threads_started":1,"update_count":1115}
I20260812 06:19:55.380287 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling LogGCOp(30a2e8bf8a824722aa3df842baf2696f): free 20743831 bytes of WAL
I20260812 06:19:55.380672 14248 log_reader.cc:385] T 30a2e8bf8a824722aa3df842baf2696f: removed 2 log segments from log reader
I20260812 06:19:55.380781 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000001 (ops 1-6)
I20260812 06:19:55.380893 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000002 (ops 7-11)
I20260812 06:19:55.386425 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: LogGCOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:55.386909 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.196750
I20260812 06:19:55.403658 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.017s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3159080,"delete_count":0,"lbm_write_time_us":4558,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:19:55.404299 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:55.516752 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.112s	user 0.091s	sys 0.017s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569844,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1501,"lbm_read_time_us":7191,"lbm_reads_lt_1ms":364,"lbm_write_time_us":20197,"lbm_writes_lt_1ms":343,"mutex_wait_us":128,"peak_mem_usage":38262756,"reinsert_count":0,"thread_start_us":323,"threads_started":5,"update_count":1500}
I20260812 06:19:55.517355 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling UndoDeltaBlockGCOp(30a2e8bf8a824722aa3df842baf2696f): 16411393 bytes on disk
I20260812 06:19:55.517802 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: UndoDeltaBlockGCOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:19:55.518217 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=10.126437
I20260812 06:19:55.561316 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.043s	user 0.032s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15529,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.561803 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:55.573256 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4283,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.573832 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:55.702258 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.128s	user 0.099s	sys 0.022s 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":170,"lbm_read_time_us":8231,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23838,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:55.703058 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=10.126437
I20260812 06:19:55.757328 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.054s	user 0.027s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19302,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.757866 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:55.769373 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4502,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.769801 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:55.917474 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.147s	user 0.095s	sys 0.052s 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":220,"lbm_read_time_us":11236,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25448,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:19:55.918025 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=10.126437
I20260812 06:19:55.963068 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.045s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19031,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.963519 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:55.973560 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3789,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.973991 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:56.099459 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.125s	user 0.101s	sys 0.024s 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":974,"lbm_read_time_us":8173,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23017,"lbm_writes_lt_1ms":443,"mutex_wait_us":263,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2000}
I20260812 06:19:56.100199 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=10.126437
I20260812 06:19:56.140123 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.040s	user 0.028s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17300,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.140532 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:56.151579 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3861,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.152129 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:56.273509 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.121s	user 0.101s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":154,"lbm_read_time_us":8467,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23464,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2000}
I20260812 06:19:56.274140 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=10.126437
I20260812 06:19:56.319546 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.045s	user 0.029s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14148,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.320228 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:56.336862 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.016s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.337459 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:56.482250 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.145s	user 0.103s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":618,"lbm_read_time_us":10502,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23983,"lbm_writes_lt_1ms":443,"mutex_wait_us":301,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2000}
I20260812 06:19:56.482765 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=10.126437
I20260812 06:19:56.526257 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.043s	user 0.019s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14216,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.526688 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:56.537227 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3935,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.537770 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:56.657720 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.120s	user 0.092s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":294,"lbm_read_time_us":9247,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21098,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2000}
I20260812 06:19:56.658346 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=10.126437
I20260812 06:19:56.695890 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.037s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16388,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.696411 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:56.706349 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3853,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.706768 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushMRSOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:56.736092 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushMRSOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.029s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1379,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1858,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:56.736881 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling LogGCOp(30a2e8bf8a824722aa3df842baf2696f): free 120553377 bytes of WAL
I20260812 06:19:56.737093 14248 log_reader.cc:385] T 30a2e8bf8a824722aa3df842baf2696f: removed 12 log segments from log reader
I20260812 06:19:56.737136 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000003 (ops 12-16)
I20260812 06:19:56.737164 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000004 (ops 17-20)
I20260812 06:19:56.737223 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000005 (ops 21-25)
I20260812 06:19:56.737267 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000006 (ops 26-30)
I20260812 06:19:56.737318 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000007 (ops 31-35)
I20260812 06:19:56.737365 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000008 (ops 36-40)
I20260812 06:19:56.737403 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000009 (ops 41-44)
I20260812 06:19:56.737445 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000010 (ops 45-49)
I20260812 06:19:56.737486 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000011 (ops 50-54)
I20260812 06:19:56.737524 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000012 (ops 55-59)
I20260812 06:19:56.737564 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000013 (ops 60-64)
I20260812 06:19:56.737603 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000014 (ops 65-69)
I20260812 06:19:56.762465 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: LogGCOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:56.762861 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling UndoDeltaBlockGCOp(30a2e8bf8a824722aa3df842baf2696f): 481 bytes on disk
I20260812 06:19:56.763449 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: UndoDeltaBlockGCOp(30a2e8bf8a824722aa3df842baf2696f) 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:56.763933 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=3.181125
I20260812 06:19:56.775955 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.012s	user 0.003s	sys 0.009s Metrics: {"bytes_written":5169287,"delete_count":0,"lbm_write_time_us":4889,"lbm_writes_lt_1ms":129,"reinsert_count":0,"update_count":630}
I20260812 06:19:56.776319 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.196750
I20260812 06:19:56.784766 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.008s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3036005,"delete_count":0,"lbm_write_time_us":2790,"lbm_writes_lt_1ms":77,"reinsert_count":0,"update_count":370}
I20260812 06:19:56.785270 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:56.961493 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.176s	user 0.139s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":725,"lbm_read_time_us":13193,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32121,"lbm_writes_lt_1ms":643,"mutex_wait_us":44,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:19:56.962039 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=14.095187
I20260812 06:19:57.015192 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.053s	user 0.022s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25140,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.015733 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:57.026351 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3873,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.026808 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:57.177901 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.151s	user 0.115s	sys 0.036s 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":587,"lbm_read_time_us":8295,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31888,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:19:57.178529 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=10.126437
I20260812 06:19:57.210500 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.029s	user 0.014s	sys 0.013s Metrics: {"bytes_written":12635684,"delete_count":0,"lbm_write_time_us":13101,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1540}
I20260812 06:19:57.211072 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:57.226081 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3774458,"delete_count":0,"lbm_write_time_us":5450,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:19:57.226663 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:57.367908 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.141s	user 0.091s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3628,"lbm_read_time_us":7992,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23580,"lbm_writes_lt_1ms":443,"mutex_wait_us":2878,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.369742 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=12.110812
I20260812 06:19:57.409813 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.040s	user 0.022s	sys 0.016s Metrics: {"bytes_written":13784351,"delete_count":0,"lbm_write_time_us":17922,"lbm_writes_lt_1ms":339,"reinsert_count":0,"update_count":1680}
I20260812 06:19:57.410259 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.196750
I20260812 06:19:57.439867 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.029s	user 0.009s	sys 0.011s Metrics: {"bytes_written":2625754,"delete_count":0,"lbm_write_time_us":4402,"lbm_writes_lt_1ms":67,"reinsert_count":0,"update_count":320}
I20260812 06:19:57.440336 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:57.450369 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3912,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.450763 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:57.614015 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.163s	user 0.121s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774764,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":164,"lbm_read_time_us":11611,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29109,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2500}
I20260812 06:19:57.614737 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=11.118625
I20260812 06:19:57.653749 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.039s	user 0.033s	sys 0.004s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":16661,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:57.654639 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:57.666810 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4428,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:57.667246 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:57.793219 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.126s	user 0.098s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1083,"lbm_read_time_us":8489,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27017,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":310,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":72192,"update_count":2000}
I20260812 06:19:57.793907 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=10.126437
I20260812 06:19:57.840485 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.046s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18789,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:57.840977 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:57.851456 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3701,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.852353 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:57.974777 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.122s	user 0.112s	sys 0.009s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1014,"lbm_read_time_us":8013,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24294,"lbm_writes_lt_1ms":443,"mutex_wait_us":322,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:57.975502 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=10.126437
I20260812 06:19:58.017859 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.042s	user 0.014s	sys 0.019s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15868,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:58.018378 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:58.028687 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.029934 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushMRSOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:58.062999 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushMRSOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.033s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":1207,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1984,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:58.063797 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling LogGCOp(30a2e8bf8a824722aa3df842baf2696f): free 120553401 bytes of WAL
I20260812 06:19:58.064049 14248 log_reader.cc:385] T 30a2e8bf8a824722aa3df842baf2696f: removed 12 log segments from log reader
I20260812 06:19:58.064116 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000015 (ops 70-74)
I20260812 06:19:58.064157 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000016 (ops 75-78)
I20260812 06:19:58.064188 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000017 (ops 79-83)
I20260812 06:19:58.064209 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000018 (ops 84-88)
I20260812 06:19:58.064239 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000019 (ops 89-93)
I20260812 06:19:58.064272 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000020 (ops 94-98)
I20260812 06:19:58.064306 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000021 (ops 99-103)
I20260812 06:19:58.064343 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000022 (ops 104-108)
I20260812 06:19:58.064371 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000023 (ops 109-113)
I20260812 06:19:58.064399 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000024 (ops 114-118)
I20260812 06:19:58.064433 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000025 (ops 119-122)
I20260812 06:19:58.064466 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000026 (ops 123-127)
I20260812 06:19:58.091133 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: LogGCOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:58.091706 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:58.116492 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.024s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6011,"lbm_writes_lt_1ms":103,"mutex_wait_us":2,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.116938 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:58.127290 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3920,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.127801 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:58.295372 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.167s	user 0.130s	sys 0.037s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877337,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":710,"lbm_read_time_us":11324,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33670,"lbm_writes_lt_1ms":643,"mutex_wait_us":50,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":89,"threads_started":1,"update_count":3000}
I20260812 06:19:58.296321 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling UndoDeltaBlockGCOp(30a2e8bf8a824722aa3df842baf2696f): 446 bytes on disk
I20260812 06:19:58.299330 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: UndoDeltaBlockGCOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":114,"lbm_reads_lt_1ms":4}
I20260812 06:19:58.300001 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=14.095187
I20260812 06:19:58.345646 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.045s	user 0.025s	sys 0.018s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20168,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.346248 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:58.364821 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.018s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6481,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.365304 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:58.517076 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.152s	user 0.103s	sys 0.038s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":991,"lbm_read_time_us":8924,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28418,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2500}
I20260812 06:19:58.517645 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=14.095187
I20260812 06:19:58.563764 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.046s	user 0.022s	sys 0.022s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":19512,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.564402 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:58.707877 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.143s	user 0.091s	sys 0.049s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672154,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":563,"lbm_read_time_us":8767,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24541,"lbm_writes_lt_1ms":443,"mutex_wait_us":293,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.708573 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=11.118625
I20260812 06:19:58.740340 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.032s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13319,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:58.741000 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:58.765234 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.024s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4300,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:58.765759 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:58.776213 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3899,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.776676 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:58.953930 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.177s	user 0.110s	sys 0.063s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":226,"lbm_read_time_us":11089,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30131,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:19:58.954677 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=10.126437
I20260812 06:19:58.990041 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.035s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14949,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:58.990640 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:59.010030 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.019s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5277,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.010496 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:59.129014 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.118s	user 0.100s	sys 0.018s 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":352,"lbm_read_time_us":6792,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23438,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:19:59.129645 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=10.126437
I20260812 06:19:59.167506 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.038s	user 0.016s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15614,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.168205 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:59.195463 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.027s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5912,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.195953 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:59.206024 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3846,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.206482 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:59.356370 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.150s	user 0.121s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":528,"lbm_read_time_us":10905,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29916,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:19:59.357136 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=11.118625
I20260812 06:19:59.391769 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.034s	user 0.011s	sys 0.023s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14850,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:59.392385 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:59.410535 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.018s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6103,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:59.411024 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushMRSOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:59.468098 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushMRSOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.057s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":262,"dirs.run_wall_time_us":1301,"drs_written":1,"lbm_read_time_us":99,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2399,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":768}
I20260812 06:19:59.468881 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling LogGCOp(30a2e8bf8a824722aa3df842baf2696f): free 120100628 bytes of WAL
I20260812 06:19:59.469108 14248 log_reader.cc:385] T 30a2e8bf8a824722aa3df842baf2696f: removed 12 log segments from log reader
I20260812 06:19:59.469156 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000027 (ops 128-132)
I20260812 06:19:59.469203 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000028 (ops 133-137)
I20260812 06:19:59.469249 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000029 (ops 138-142)
I20260812 06:19:59.469307 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000030 (ops 143-147)
I20260812 06:19:59.469357 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000031 (ops 148-152)
I20260812 06:19:59.469409 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000032 (ops 153-156)
I20260812 06:19:59.469444 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000033 (ops 157-161)
I20260812 06:19:59.469480 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000034 (ops 162-166)
I20260812 06:19:59.469519 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000035 (ops 167-170)
I20260812 06:19:59.469558 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000036 (ops 171-175)
I20260812 06:19:59.469596 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000037 (ops 176-180)
I20260812 06:19:59.469632 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000038 (ops 181-184)
I20260812 06:19:59.494292 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: LogGCOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:59.494724 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=6.157687
I20260812 06:19:59.522609 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.028s	user 0.014s	sys 0.011s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12239,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:59.523133 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling LogGCOp(30a2e8bf8a824722aa3df842baf2696f): free 8767138 bytes of WAL
I20260812 06:19:59.523341 14248 log_reader.cc:385] T 30a2e8bf8a824722aa3df842baf2696f: removed 1 log segments from log reader
I20260812 06:19:59.523387 14248 log.cc:1079] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/30a2e8bf8a824722aa3df842baf2696f/wal-000000039 (ops 185-189)
I20260812 06:19:59.525068 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: LogGCOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:59.525406 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling UndoDeltaBlockGCOp(30a2e8bf8a824722aa3df842baf2696f): 473 bytes on disk
I20260812 06:19:59.525828 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: UndoDeltaBlockGCOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:59.526345 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:59.538944 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4617,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.539428 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f): perf score=1.000000
I20260812 06:19:59.719259 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: MajorDeltaCompactionOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.180s	user 0.130s	sys 0.049s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979743,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1025,"lbm_read_time_us":12842,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35621,"lbm_writes_lt_1ms":743,"mutex_wait_us":267,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:19:59.720754 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=14.095187
I20260812 06:19:59.744654 14147 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.651s	user 1.798s	sys 0.111s
I20260812 06:19:59.770290 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.049s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21314,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.770948 14308 maintenance_manager.cc:419] P e1fc0f0fd5fd436a8301fcf0cb17a06c: Scheduling FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f): perf score=2.188937
I20260812 06:19:59.775939 14147 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.031s	user 0.003s	sys 0.004s
I20260812 06:19:59.776549 14147 tablet_server.cc:179] TabletServer@127.13.208.193:0 shutting down...
I20260812 06:19:59.783432 14248 maintenance_manager.cc:643] P e1fc0f0fd5fd436a8301fcf0cb17a06c: FlushDeltaMemStoresOp(30a2e8bf8a824722aa3df842baf2696f) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4641,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.784013 14147 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:59.784376 14147 tablet_replica.cc:333] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c: stopping tablet replica
I20260812 06:19:59.784591 14147 raft_consensus.cc:2243] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:59.784818 14147 raft_consensus.cc:2272] T 30a2e8bf8a824722aa3df842baf2696f P e1fc0f0fd5fd436a8301fcf0cb17a06c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:59.799336 14147 tablet_server.cc:196] TabletServer@127.13.208.193:0 shutdown complete.
I20260812 06:19:59.804221 14147 master.cc:562] Master@127.13.208.254:34725 shutting down...
I20260812 06:19:59.807814 14147 raft_consensus.cc:2243] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:59.807969 14147 raft_consensus.cc:2272] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:59.808023 14147 tablet_replica.cc:333] T 00000000000000000000000000000000 P aacaf0bd8d4949e48a4dbb76f746688d: stopping tablet replica
I20260812 06:19:59.820422 14147 master.cc:584] Master@127.13.208.254:34725 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5072 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:59.905319 14147 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.208.254:34007
I20260812 06:19:59.905679 14147 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:59.907706 14338 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:59.907845 14147 server_base.cc:1061] running on GCE node
W20260812 06:19:59.907917 14339 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:59.908252 14341 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:59.908490 14147 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:59.908535 14147 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:59.908551 14147 hybrid_clock.cc:648] HybridClock initialized: now 1786515599908551 us; error 0 us; skew 500 ppm
I20260812 06:19:59.909344 14147 webserver.cc:533] Webserver started at http://127.13.208.254:45279/ using document root <none> and password file <none>
I20260812 06:19:59.909482 14147 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:59.909523 14147 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:59.909654 14147 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:59.910037 14147 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/master-0-root/instance:
uuid: "a75e4ee9c0f945f2843788f32c6caa04"
format_stamp: "Formatted at 2026-08-12 06:19:59 on dist-test-slave-bxbt"
I20260812 06:19:59.911595 14147 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:59.912622 14346 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:59.912940 14147 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:59.913033 14147 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/master-0-root
uuid: "a75e4ee9c0f945f2843788f32c6caa04"
format_stamp: "Formatted at 2026-08-12 06:19:59 on dist-test-slave-bxbt"
I20260812 06:19:59.913116 14147 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-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:59.920806 14147 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:59.921154 14147 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:59.925324 14147 rpc_server.cc:307] RPC server started. Bound to: 127.13.208.254:34007
I20260812 06:19:59.928038 14399 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:59.928121 14398 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.208.254:34007 every 8 connection(s)
I20260812 06:19:59.934219 14399 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04: Bootstrap starting.
I20260812 06:19:59.936381 14399 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:59.943156 14399 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04: No bootstrap required, opened a new log
I20260812 06:19:59.943557 14399 raft_consensus.cc:359] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a75e4ee9c0f945f2843788f32c6caa04" member_type: VOTER }
I20260812 06:19:59.943646 14399 raft_consensus.cc:385] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:59.943722 14399 raft_consensus.cc:740] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a75e4ee9c0f945f2843788f32c6caa04, State: Initialized, Role: FOLLOWER
I20260812 06:19:59.943869 14399 consensus_queue.cc:260] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [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: "a75e4ee9c0f945f2843788f32c6caa04" member_type: VOTER }
I20260812 06:19:59.943938 14399 raft_consensus.cc:399] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:59.943961 14399 raft_consensus.cc:493] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:59.943997 14399 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:59.944705 14399 raft_consensus.cc:515] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a75e4ee9c0f945f2843788f32c6caa04" member_type: VOTER }
I20260812 06:19:59.944823 14399 leader_election.cc:304] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [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: a75e4ee9c0f945f2843788f32c6caa04; no voters: 
I20260812 06:19:59.944990 14399 leader_election.cc:290] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:59.945142 14402 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:59.945403 14402 raft_consensus.cc:697] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [term 1 LEADER]: Becoming Leader. State: Replica: a75e4ee9c0f945f2843788f32c6caa04, State: Running, Role: LEADER
I20260812 06:19:59.945497 14399 sys_catalog.cc:565] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:59.945546 14402 consensus_queue.cc:237] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [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: "a75e4ee9c0f945f2843788f32c6caa04" member_type: VOTER }
I20260812 06:19:59.946028 14404 sys_catalog.cc:455] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [sys.catalog]: SysCatalogTable state changed. Reason: New leader a75e4ee9c0f945f2843788f32c6caa04. Latest consensus state: current_term: 1 leader_uuid: "a75e4ee9c0f945f2843788f32c6caa04" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a75e4ee9c0f945f2843788f32c6caa04" member_type: VOTER } }
I20260812 06:19:59.946013 14403 sys_catalog.cc:455] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a75e4ee9c0f945f2843788f32c6caa04" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a75e4ee9c0f945f2843788f32c6caa04" member_type: VOTER } }
I20260812 06:19:59.946161 14404 sys_catalog.cc:458] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:59.946236 14403 sys_catalog.cc:458] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:59.946853 14409 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:59.947645 14409 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:59.947860 14147 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:59.949468 14409 catalog_manager.cc:1383] Generated new cluster ID: e0af84e8d6984a2e9555acb256b107c3
I20260812 06:19:59.949529 14409 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:59.974534 14409 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:59.975121 14409 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:59.981281 14409 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04: Generated new TSK 0
I20260812 06:19:59.981469 14409 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:00.012552 14147 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:00.014709 14420 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:20:00.014801 14147 server_base.cc:1061] running on GCE node
W20260812 06:20:00.014859 14421 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:20:00.014758 14423 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:20:00.015293 14147 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:00.015343 14147 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:20:00.015359 14147 hybrid_clock.cc:648] HybridClock initialized: now 1786515600015360 us; error 0 us; skew 500 ppm
I20260812 06:20:00.016237 14147 webserver.cc:533] Webserver started at http://127.13.208.193:39925/ using document root <none> and password file <none>
I20260812 06:20:00.016422 14147 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:00.016489 14147 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:00.016572 14147 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:00.016979 14147 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/instance:
uuid: "db13a8446bc04c32a34e32e64cece2b4"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-bxbt"
I20260812 06:20:00.018432 14147 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:00.019297 14428 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:20:00.019546 14147 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:00.019616 14147 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root
uuid: "db13a8446bc04c32a34e32e64cece2b4"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-bxbt"
I20260812 06:20:00.019737 14147 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-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:20:00.034332 14147 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:00.034637 14147 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:00.034883 14147 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:00.035363 14147 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:00.035404 14147 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.035462 14147 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:00.035501 14147 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.039729 14147 rpc_server.cc:307] RPC server started. Bound to: 127.13.208.193:37565
I20260812 06:20:00.039834 14491 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.208.193:37565 every 8 connection(s)
I20260812 06:20:00.048058 14492 heartbeater.cc:344] Connected to a master server at 127.13.208.254:34007
I20260812 06:20:00.048197 14492 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:00.048410 14492 heartbeater.cc:507] Master 127.13.208.254:34007 requested a full tablet report, sending...
I20260812 06:20:00.049000 14363 ts_manager.cc:194] Registered new tserver with Master: db13a8446bc04c32a34e32e64cece2b4 (127.13.208.193:37565)
I20260812 06:20:00.049166 14147 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008952792s
I20260812 06:20:00.049996 14363 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41646
I20260812 06:20:00.056392 14363 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41652:
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:20:00.065189 14456 tablet_service.cc:1511] Processing CreateTablet for tablet 459cee687f194fedba11589a188dd4d5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=e5056f9a614f4e38bed1dc42eca93ea8]), partition=
I20260812 06:20:00.065441 14456 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 459cee687f194fedba11589a188dd4d5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:00.067314 14504 tablet_bootstrap.cc:492] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Bootstrap starting.
I20260812 06:20:00.068159 14504 tablet_bootstrap.cc:654] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:00.069190 14504 tablet_bootstrap.cc:492] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: No bootstrap required, opened a new log
I20260812 06:20:00.069281 14504 ts_tablet_manager.cc:1403] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:00.069691 14504 raft_consensus.cc:359] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "db13a8446bc04c32a34e32e64cece2b4" member_type: VOTER last_known_addr { host: "127.13.208.193" port: 37565 } }
I20260812 06:20:00.069774 14504 raft_consensus.cc:385] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:00.069839 14504 raft_consensus.cc:740] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: db13a8446bc04c32a34e32e64cece2b4, State: Initialized, Role: FOLLOWER
I20260812 06:20:00.070005 14504 consensus_queue.cc:260] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4 [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: "db13a8446bc04c32a34e32e64cece2b4" member_type: VOTER last_known_addr { host: "127.13.208.193" port: 37565 } }
I20260812 06:20:00.070106 14504 raft_consensus.cc:399] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:00.070128 14504 raft_consensus.cc:493] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:00.070158 14504 raft_consensus.cc:3060] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:00.070920 14504 raft_consensus.cc:515] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "db13a8446bc04c32a34e32e64cece2b4" member_type: VOTER last_known_addr { host: "127.13.208.193" port: 37565 } }
I20260812 06:20:00.071061 14504 leader_election.cc:304] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4 [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: db13a8446bc04c32a34e32e64cece2b4; no voters: 
I20260812 06:20:00.071261 14504 leader_election.cc:290] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:00.071384 14506 raft_consensus.cc:2804] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:00.071617 14504 ts_tablet_manager.cc:1434] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:00.071666 14492 heartbeater.cc:499] Master 127.13.208.254:34007 was elected leader, sending a full tablet report...
I20260812 06:20:00.071693 14506 raft_consensus.cc:697] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4 [term 1 LEADER]: Becoming Leader. State: Replica: db13a8446bc04c32a34e32e64cece2b4, State: Running, Role: LEADER
I20260812 06:20:00.071906 14506 consensus_queue.cc:237] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4 [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: "db13a8446bc04c32a34e32e64cece2b4" member_type: VOTER last_known_addr { host: "127.13.208.193" port: 37565 } }
I20260812 06:20:00.073247 14363 catalog_manager.cc:5719] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4 reported cstate change: term changed from 0 to 1, leader changed from <none> to db13a8446bc04c32a34e32e64cece2b4 (127.13.208.193). New cstate: current_term: 1 leader_uuid: "db13a8446bc04c32a34e32e64cece2b4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "db13a8446bc04c32a34e32e64cece2b4" member_type: VOTER last_known_addr { host: "127.13.208.193" port: 37565 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:00.130075 14147 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.021s	sys 0.000s
I20260812 06:20:00.290627 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushMRSOp(459cee687f194fedba11589a188dd4d5): perf score=22.031503
I20260812 06:20:00.462644 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushMRSOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.172s	user 0.120s	sys 0.048s Metrics: {"bytes_written":12676710,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":785,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45658,"lbm_writes_lt_1ms":866,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":3840,"update_count":1545}
I20260812 06:20:00.463250 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling LogGCOp(459cee687f194fedba11589a188dd4d5): free 20743831 bytes of WAL
I20260812 06:20:00.463483 14433 log_reader.cc:385] T 459cee687f194fedba11589a188dd4d5: removed 2 log segments from log reader
I20260812 06:20:00.463531 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000001 (ops 1-6)
I20260812 06:20:00.463560 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000002 (ops 7-11)
I20260812 06:20:00.467458 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: LogGCOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:00.467870 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling UndoDeltaBlockGCOp(459cee687f194fedba11589a188dd4d5): 20513813 bytes on disk
I20260812 06:20:00.468271 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: UndoDeltaBlockGCOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:20:00.468657 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:00.485968 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.017s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":3758,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:20:00.486402 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:00.496570 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3839,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.497004 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:00.667799 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.171s	user 0.120s	sys 0.042s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815798,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":880,"lbm_read_time_us":11908,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29560,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":373,"threads_started":5,"update_count":2500}
I20260812 06:20:00.668306 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=14.095187
I20260812 06:20:00.718971 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.050s	user 0.014s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19452,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.719466 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:00.730628 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3859,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.731303 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:00.879415 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.148s	user 0.124s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":638,"lbm_read_time_us":9170,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30955,"lbm_writes_lt_1ms":543,"mutex_wait_us":306,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":46336,"update_count":2500}
I20260812 06:20:00.880170 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=10.126437
I20260812 06:20:00.914604 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.034s	user 0.011s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13414,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:00.915060 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:00.929297 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4868,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.929885 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:01.052155 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.122s	user 0.110s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":253,"lbm_read_time_us":9397,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22569,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2000}
I20260812 06:20:01.052613 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=10.126437
I20260812 06:20:01.104573 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.052s	user 0.025s	sys 0.020s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":14674,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:01.105306 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:01.118970 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5451,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.119457 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:01.291723 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.172s	user 0.110s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":357,"lbm_read_time_us":11635,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26758,"lbm_writes_lt_1ms":443,"mutex_wait_us":85,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:01.292516 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=11.118625
I20260812 06:20:01.324434 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.032s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13215,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:01.325101 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:01.350662 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.025s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4968,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.351140 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:01.361414 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3821,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.361963 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:01.583352 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.221s	user 0.155s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":617,"lbm_read_time_us":10216,"lbm_reads_lt_1ms":573,"lbm_write_time_us":35382,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":81280,"update_count":2500}
I20260812 06:20:01.584117 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=14.095187
I20260812 06:20:01.641312 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.057s	user 0.034s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22270,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:01.641809 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:01.652885 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4174,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.653298 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushMRSOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:01.684900 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushMRSOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.031s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":1407,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1356,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:01.685458 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling LogGCOp(459cee687f194fedba11589a188dd4d5): free 112239304 bytes of WAL
I20260812 06:20:01.685674 14433 log_reader.cc:385] T 459cee687f194fedba11589a188dd4d5: removed 11 log segments from log reader
I20260812 06:20:01.685729 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000003 (ops 12-16)
I20260812 06:20:01.685782 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000004 (ops 17-21)
I20260812 06:20:01.685832 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000005 (ops 22-26)
I20260812 06:20:01.685874 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000006 (ops 27-31)
I20260812 06:20:01.685912 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000007 (ops 32-36)
I20260812 06:20:01.685948 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000008 (ops 37-41)
I20260812 06:20:01.685986 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000009 (ops 42-46)
I20260812 06:20:01.686023 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000010 (ops 47-51)
I20260812 06:20:01.686067 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000011 (ops 52-56)
I20260812 06:20:01.686103 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000012 (ops 57-60)
I20260812 06:20:01.686141 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000013 (ops 61-65)
I20260812 06:20:01.709723 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: LogGCOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:01.710258 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=3.181125
I20260812 06:20:01.732353 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.022s	user 0.011s	sys 0.008s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":7480,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:01.732944 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling LogGCOp(459cee687f194fedba11589a188dd4d5): free 12017983 bytes of WAL
I20260812 06:20:01.733184 14433 log_reader.cc:385] T 459cee687f194fedba11589a188dd4d5: removed 1 log segments from log reader
I20260812 06:20:01.733274 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000014 (ops 66-70)
I20260812 06:20:01.736618 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: LogGCOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:01.736943 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:01.746831 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3693,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.747238 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:01.987198 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.240s	user 0.150s	sys 0.087s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":784,"lbm_read_time_us":17389,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38540,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9344,"thread_start_us":103,"threads_started":1,"update_count":3500}
I20260812 06:20:01.987938 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling UndoDeltaBlockGCOp(459cee687f194fedba11589a188dd4d5): 448 bytes on disk
I20260812 06:20:01.988564 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: UndoDeltaBlockGCOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:20:01.989193 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=18.063937
I20260812 06:20:02.059036 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.070s	user 0.034s	sys 0.021s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":26328,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:02.059476 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:02.069859 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3938,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.070523 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:02.267881 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.197s	user 0.142s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":662,"lbm_read_time_us":13274,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31563,"lbm_writes_lt_1ms":643,"mutex_wait_us":68,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":3000}
I20260812 06:20:02.268467 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=16.079562
I20260812 06:20:02.322999 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.054s	user 0.034s	sys 0.016s Metrics: {"bytes_written":17640627,"delete_count":0,"lbm_write_time_us":23318,"lbm_writes_lt_1ms":433,"reinsert_count":0,"update_count":2150}
I20260812 06:20:02.323565 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:02.344749 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.021s	user 0.012s	sys 0.001s Metrics: {"bytes_written":3282159,"delete_count":0,"lbm_write_time_us":5152,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:20:02.345185 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:02.354945 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3666,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.355363 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:02.555374 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.200s	user 0.127s	sys 0.071s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918186,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":194,"lbm_read_time_us":12920,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31961,"lbm_writes_lt_1ms":643,"mutex_wait_us":31,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":125952,"update_count":3000}
I20260812 06:20:02.556167 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=16.079562
I20260812 06:20:02.620898 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.065s	user 0.040s	sys 0.008s Metrics: {"bytes_written":17558582,"delete_count":0,"lbm_write_time_us":21817,"lbm_writes_lt_1ms":431,"reinsert_count":0,"update_count":2140}
I20260812 06:20:02.621346 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=5.165500
I20260812 06:20:02.641198 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.020s	user 0.010s	sys 0.008s Metrics: {"bytes_written":7056405,"delete_count":0,"lbm_write_time_us":7960,"lbm_writes_lt_1ms":175,"reinsert_count":0,"update_count":860}
I20260812 06:20:02.641695 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:02.864914 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.223s	user 0.151s	sys 0.059s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1316,"lbm_read_time_us":14227,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36688,"lbm_writes_lt_1ms":643,"mutex_wait_us":436,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19712,"update_count":3000}
I20260812 06:20:02.865535 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=18.063937
I20260812 06:20:02.933215 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.067s	user 0.036s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26107,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:02.933699 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:02.944674 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3958,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.945374 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:03.149159 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.204s	user 0.116s	sys 0.087s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":338,"lbm_read_time_us":14358,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34213,"lbm_writes_lt_1ms":643,"mutex_wait_us":50,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:20:03.149737 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=15.087375
I20260812 06:20:03.196053 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.046s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":20822,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:03.196641 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:03.212589 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6131,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.213169 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushMRSOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:03.241961 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushMRSOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1453,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1573,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:03.242666 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling LogGCOp(459cee687f194fedba11589a188dd4d5): free 121006400 bytes of WAL
I20260812 06:20:03.242908 14433 log_reader.cc:385] T 459cee687f194fedba11589a188dd4d5: removed 12 log segments from log reader
I20260812 06:20:03.242959 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000015 (ops 71-75)
I20260812 06:20:03.243007 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000016 (ops 76-80)
I20260812 06:20:03.243049 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000017 (ops 81-85)
I20260812 06:20:03.243105 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000018 (ops 86-90)
I20260812 06:20:03.243144 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000019 (ops 91-95)
I20260812 06:20:03.243180 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000020 (ops 96-100)
I20260812 06:20:03.243223 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000021 (ops 101-105)
I20260812 06:20:03.243261 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000022 (ops 106-110)
I20260812 06:20:03.243299 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000023 (ops 111-115)
I20260812 06:20:03.243340 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000024 (ops 116-120)
I20260812 06:20:03.243376 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000025 (ops 121-124)
I20260812 06:20:03.243415 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000026 (ops 125-129)
I20260812 06:20:03.269443 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: LogGCOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:03.269866 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=3.181125
I20260812 06:20:03.284184 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4308,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:03.284761 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:03.294816 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3608,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.295387 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:03.527969 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.232s	user 0.132s	sys 0.089s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020719,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":585,"lbm_read_time_us":16192,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40571,"lbm_writes_lt_1ms":743,"mutex_wait_us":44,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":22272,"thread_start_us":90,"threads_started":1,"update_count":3500}
I20260812 06:20:03.528692 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=18.063937
I20260812 06:20:03.580752 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.052s	user 0.039s	sys 0.012s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":23262,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:03.581538 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling UndoDeltaBlockGCOp(459cee687f194fedba11589a188dd4d5): 482 bytes on disk
I20260812 06:20:03.582055 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: UndoDeltaBlockGCOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:20:03.582674 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:03.598999 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.016s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6517,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.599505 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:03.770046 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.170s	user 0.125s	sys 0.036s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":201,"lbm_read_time_us":12809,"lbm_reads_lt_1ms":668,"lbm_write_time_us":32975,"lbm_writes_lt_1ms":643,"mutex_wait_us":69,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":3000}
I20260812 06:20:03.770828 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=14.095187
I20260812 06:20:03.822582 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.052s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19153,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.823091 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:03.834971 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4181,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.835515 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:04.000777 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.165s	user 0.127s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":831,"lbm_read_time_us":10900,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30417,"lbm_writes_lt_1ms":543,"mutex_wait_us":370,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:20:04.001430 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=14.095187
I20260812 06:20:04.043856 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.042s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19345,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.044426 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:04.215180 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.171s	user 0.131s	sys 0.033s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713155,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":820,"lbm_read_time_us":11042,"lbm_reads_lt_1ms":467,"lbm_write_time_us":28326,"lbm_writes_lt_1ms":443,"mutex_wait_us":542,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19328,"update_count":2000}
I20260812 06:20:04.215761 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=11.118625
I20260812 06:20:04.251849 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.036s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15391,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:04.252893 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:04.266773 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5259,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:04.267333 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:04.400524 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.133s	user 0.097s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":214,"lbm_read_time_us":9343,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26656,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:20:04.401360 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=11.118625
I20260812 06:20:04.435102 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.034s	user 0.026s	sys 0.004s Metrics: {"bytes_written":12676712,"delete_count":0,"lbm_write_time_us":14239,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1545}
I20260812 06:20:04.435772 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:04.451478 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.015s	user 0.005s	sys 0.009s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":6308,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:20:04.452052 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:04.580186 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.128s	user 0.102s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1069,"lbm_read_time_us":8212,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24668,"lbm_writes_lt_1ms":443,"mutex_wait_us":278,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:20:04.581099 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=10.126437
I20260812 06:20:04.622562 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.041s	user 0.018s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16272,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.623178 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:04.635759 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.012s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4457,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.636548 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushMRSOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:04.667933 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushMRSOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.031s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":275,"dirs.run_wall_time_us":1536,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1703,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:04.668645 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling LogGCOp(459cee687f194fedba11589a188dd4d5): free 120553692 bytes of WAL
I20260812 06:20:04.669021 14433 log_reader.cc:385] T 459cee687f194fedba11589a188dd4d5: removed 12 log segments from log reader
I20260812 06:20:04.669083 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000027 (ops 130-134)
I20260812 06:20:04.669114 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000028 (ops 135-138)
I20260812 06:20:04.669324 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000029 (ops 139-143)
I20260812 06:20:04.669451 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000030 (ops 144-148)
I20260812 06:20:04.669507 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000031 (ops 149-153)
I20260812 06:20:04.669528 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000032 (ops 154-158)
I20260812 06:20:04.669564 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000033 (ops 159-163)
I20260812 06:20:04.669605 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000034 (ops 164-168)
I20260812 06:20:04.669647 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000035 (ops 169-172)
I20260812 06:20:04.669732 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000036 (ops 173-177)
I20260812 06:20:04.669795 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000037 (ops 178-182)
I20260812 06:20:04.669879 14433 log.cc:1079] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: Deleting log segment in path: /tmp/dist-test-taskM57kaO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594822398-14147-0/minicluster-data/ts-0-root/wals/459cee687f194fedba11589a188dd4d5/wal-000000038 (ops 183-187)
I20260812 06:20:04.697703 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: LogGCOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:04.698307 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=3.181125
I20260812 06:20:04.712133 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4964169,"delete_count":0,"lbm_write_time_us":5543,"lbm_writes_lt_1ms":124,"reinsert_count":0,"update_count":605}
I20260812 06:20:04.712635 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:04.723872 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.011s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3241130,"delete_count":0,"lbm_write_time_us":3539,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:20:04.724572 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling UndoDeltaBlockGCOp(459cee687f194fedba11589a188dd4d5): 461 bytes on disk
I20260812 06:20:04.725098 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: UndoDeltaBlockGCOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:20:04.725855 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:04.911103 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.185s	user 0.135s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918315,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":474,"lbm_read_time_us":10886,"lbm_reads_lt_1ms":666,"lbm_write_time_us":39366,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":92,"threads_started":1,"update_count":3000}
I20260812 06:20:04.911921 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=14.095187
I20260812 06:20:04.959125 14147 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.829s	user 1.839s	sys 0.153s
I20260812 06:20:04.962493 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.050s	user 0.030s	sys 0.014s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20378,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.963073 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5): perf score=2.188937
I20260812 06:20:04.980479 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: FlushDeltaMemStoresOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6867,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":500}
I20260812 06:20:04.981218 14493 maintenance_manager.cc:419] P db13a8446bc04c32a34e32e64cece2b4: Scheduling MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5): perf score=1.000000
I20260812 06:20:05.026158 14147 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.067s	user 0.001s	sys 0.000s
I20260812 06:20:05.026721 14147 tablet_server.cc:179] TabletServer@127.13.208.193:0 shutting down...
I20260812 06:20:05.109297 14433 maintenance_manager.cc:643] P db13a8446bc04c32a34e32e64cece2b4: MajorDeltaCompactionOp(459cee687f194fedba11589a188dd4d5) complete. Timing: real 0.128s	user 0.090s	sys 0.038s Metrics: {"cfile_cache_hit":401,"cfile_cache_hit_bytes":16409769,"cfile_cache_miss":131,"cfile_cache_miss_bytes":8405916,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":256,"lbm_read_time_us":4349,"lbm_reads_lt_1ms":163,"lbm_write_time_us":28231,"lbm_writes_lt_1ms":543,"mutex_wait_us":77,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":29056,"update_count":2500}
I20260812 06:20:05.109956 14147 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:05.110272 14147 tablet_replica.cc:333] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4: stopping tablet replica
I20260812 06:20:05.110446 14147 raft_consensus.cc:2243] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:05.110647 14147 raft_consensus.cc:2272] T 459cee687f194fedba11589a188dd4d5 P db13a8446bc04c32a34e32e64cece2b4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:05.114430 14147 tablet_server.cc:196] TabletServer@127.13.208.193:0 shutdown complete.
I20260812 06:20:05.154978 14147 master.cc:562] Master@127.13.208.254:34007 shutting down...
I20260812 06:20:05.159128 14147 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:05.159375 14147 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:05.159485 14147 tablet_replica.cc:333] T 00000000000000000000000000000000 P a75e4ee9c0f945f2843788f32c6caa04: stopping tablet replica
I20260812 06:20:05.172181 14147 master.cc:584] Master@127.13.208.254:34007 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5351 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10425 ms total)

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