[==========] 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:20:07.197816 17116 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.16.183.62:33299
I20260812 06:20:07.198939 17116 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:20:07.199633 17116 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:07.206135 17127 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:07.206116 17129 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:07.206414 17125 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:07.206414 17116 server_base.cc:1061] running on GCE node
I20260812 06:20:07.207026 17116 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:07.207147 17116 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:07.207194 17116 hybrid_clock.cc:648] HybridClock initialized: now 1786515607207192 us; error 0 us; skew 500 ppm
I20260812 06:20:07.209231 17116 webserver.cc:533] Webserver started at http://127.16.183.62:41215/ using document root <none> and password file <none>
I20260812 06:20:07.209837 17116 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:07.209932 17116 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:07.210189 17116 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:07.212031 17116 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/master-0-root/instance:
uuid: "e6cb55b52e0f45c0b2f68fdc05977d42"
format_stamp: "Formatted at 2026-08-12 06:20:07 on dist-test-slave-gw5c"
I20260812 06:20:07.215814 17116 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:07.218384 17138 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:07.219594 17116 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:07.219749 17116 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/master-0-root
uuid: "e6cb55b52e0f45c0b2f68fdc05977d42"
format_stamp: "Formatted at 2026-08-12 06:20:07 on dist-test-slave-gw5c"
I20260812 06:20:07.219872 17116 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-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:20:07.237251 17116 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:07.238044 17116 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:20:07.238243 17116 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:07.247020 17116 rpc_server.cc:307] RPC server started. Bound to: 127.16.183.62:33299
I20260812 06:20:07.247066 17233 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.183.62:33299 every 8 connection(s)
I20260812 06:20:07.249634 17234 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:20:07.255858 17234 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42: Bootstrap starting.
I20260812 06:20:07.258427 17234 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:07.259481 17234 log.cc:826] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:07.261337 17234 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42: No bootstrap required, opened a new log
I20260812 06:20:07.264525 17234 raft_consensus.cc:359] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e6cb55b52e0f45c0b2f68fdc05977d42" member_type: VOTER }
I20260812 06:20:07.264735 17234 raft_consensus.cc:385] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:07.264778 17234 raft_consensus.cc:740] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e6cb55b52e0f45c0b2f68fdc05977d42, State: Initialized, Role: FOLLOWER
I20260812 06:20:07.265359 17234 consensus_queue.cc:260] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [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: "e6cb55b52e0f45c0b2f68fdc05977d42" member_type: VOTER }
I20260812 06:20:07.265504 17234 raft_consensus.cc:399] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:07.265548 17234 raft_consensus.cc:493] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:07.265647 17234 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:07.266505 17234 raft_consensus.cc:515] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e6cb55b52e0f45c0b2f68fdc05977d42" member_type: VOTER }
I20260812 06:20:07.266933 17234 leader_election.cc:304] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [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: e6cb55b52e0f45c0b2f68fdc05977d42; no voters: 
I20260812 06:20:07.267269 17234 leader_election.cc:290] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:07.267468 17238 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:07.267973 17238 raft_consensus.cc:697] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [term 1 LEADER]: Becoming Leader. State: Replica: e6cb55b52e0f45c0b2f68fdc05977d42, State: Running, Role: LEADER
I20260812 06:20:07.268489 17234 sys_catalog.cc:565] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:07.268513 17238 consensus_queue.cc:237] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [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: "e6cb55b52e0f45c0b2f68fdc05977d42" member_type: VOTER }
I20260812 06:20:07.270726 17243 sys_catalog.cc:455] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [sys.catalog]: SysCatalogTable state changed. Reason: New leader e6cb55b52e0f45c0b2f68fdc05977d42. Latest consensus state: current_term: 1 leader_uuid: "e6cb55b52e0f45c0b2f68fdc05977d42" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e6cb55b52e0f45c0b2f68fdc05977d42" member_type: VOTER } }
I20260812 06:20:07.270747 17241 sys_catalog.cc:455] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e6cb55b52e0f45c0b2f68fdc05977d42" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e6cb55b52e0f45c0b2f68fdc05977d42" member_type: VOTER } }
I20260812 06:20:07.270870 17243 sys_catalog.cc:458] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:07.270871 17241 sys_catalog.cc:458] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:07.271087 17116 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:07.271245 17268 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:07.273630 17268 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:07.278775 17268 catalog_manager.cc:1383] Generated new cluster ID: d2cc9a9f50d94662b96c4abaa0782f33
I20260812 06:20:07.278865 17268 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:07.306180 17268 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:07.307190 17268 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:07.318899 17268 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42: Generated new TSK 0
I20260812 06:20:07.319757 17268 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:07.336166 17116 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:07.339066 17276 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:07.339147 17278 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:07.339143 17274 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:07.339859 17116 server_base.cc:1061] running on GCE node
I20260812 06:20:07.340088 17116 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:07.340131 17116 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:07.340147 17116 hybrid_clock.cc:648] HybridClock initialized: now 1786515607340148 us; error 0 us; skew 500 ppm
I20260812 06:20:07.341223 17116 webserver.cc:533] Webserver started at http://127.16.183.1:39237/ using document root <none> and password file <none>
I20260812 06:20:07.341437 17116 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:07.341507 17116 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:07.341599 17116 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:07.342027 17116 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/instance:
uuid: "2a2efc160a0e4126baddd04ff2e4c151"
format_stamp: "Formatted at 2026-08-12 06:20:07 on dist-test-slave-gw5c"
I20260812 06:20:07.343767 17116 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:07.344852 17290 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:07.345118 17116 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:07.345192 17116 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root
uuid: "2a2efc160a0e4126baddd04ff2e4c151"
format_stamp: "Formatted at 2026-08-12 06:20:07 on dist-test-slave-gw5c"
I20260812 06:20:07.345289 17116 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-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:07.349812 17116 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:07.350291 17116 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:07.350813 17116 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:07.351768 17116 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:07.351823 17116 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:07.351895 17116 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:07.351930 17116 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:07.359046 17116 rpc_server.cc:307] RPC server started. Bound to: 127.16.183.1:36263
I20260812 06:20:07.359061 17411 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.183.1:36263 every 8 connection(s)
I20260812 06:20:07.371874 17413 heartbeater.cc:344] Connected to a master server at 127.16.183.62:33299
I20260812 06:20:07.372265 17413 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:07.372857 17413 heartbeater.cc:507] Master 127.16.183.62:33299 requested a full tablet report, sending...
I20260812 06:20:07.374918 17166 ts_manager.cc:194] Registered new tserver with Master: 2a2efc160a0e4126baddd04ff2e4c151 (127.16.183.1:36263)
I20260812 06:20:07.375718 17116 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015833498s
I20260812 06:20:07.376590 17166 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33706
I20260812 06:20:07.390444 17166 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33714:
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:07.408427 17335 tablet_service.cc:1511] Processing CreateTablet for tablet dab500ab3095440f979c37253414e157 (DEFAULT_TABLE table=heavy-update-compaction-test [id=aab28a305d84437996426055bac123d2]), partition=
I20260812 06:20:07.409099 17335 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet dab500ab3095440f979c37253414e157. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:07.412811 17435 tablet_bootstrap.cc:492] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Bootstrap starting.
I20260812 06:20:07.414023 17435 tablet_bootstrap.cc:654] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:07.415611 17435 tablet_bootstrap.cc:492] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: No bootstrap required, opened a new log
I20260812 06:20:07.415741 17435 ts_tablet_manager.cc:1403] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Time spent bootstrapping tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:07.416260 17435 raft_consensus.cc:359] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2a2efc160a0e4126baddd04ff2e4c151" member_type: VOTER last_known_addr { host: "127.16.183.1" port: 36263 } }
I20260812 06:20:07.416379 17435 raft_consensus.cc:385] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:07.416404 17435 raft_consensus.cc:740] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2a2efc160a0e4126baddd04ff2e4c151, State: Initialized, Role: FOLLOWER
I20260812 06:20:07.416599 17435 consensus_queue.cc:260] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151 [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: "2a2efc160a0e4126baddd04ff2e4c151" member_type: VOTER last_known_addr { host: "127.16.183.1" port: 36263 } }
I20260812 06:20:07.416759 17435 raft_consensus.cc:399] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:07.416826 17435 raft_consensus.cc:493] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:07.416894 17435 raft_consensus.cc:3060] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:07.418259 17435 raft_consensus.cc:515] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2a2efc160a0e4126baddd04ff2e4c151" member_type: VOTER last_known_addr { host: "127.16.183.1" port: 36263 } }
I20260812 06:20:07.418437 17435 leader_election.cc:304] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151 [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: 2a2efc160a0e4126baddd04ff2e4c151; no voters: 
I20260812 06:20:07.418699 17435 leader_election.cc:290] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:07.418833 17439 raft_consensus.cc:2804] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:07.419127 17439 raft_consensus.cc:697] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151 [term 1 LEADER]: Becoming Leader. State: Replica: 2a2efc160a0e4126baddd04ff2e4c151, State: Running, Role: LEADER
I20260812 06:20:07.419153 17435 ts_tablet_manager.cc:1434] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:07.419361 17439 consensus_queue.cc:237] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151 [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: "2a2efc160a0e4126baddd04ff2e4c151" member_type: VOTER last_known_addr { host: "127.16.183.1" port: 36263 } }
I20260812 06:20:07.419721 17413 heartbeater.cc:499] Master 127.16.183.62:33299 was elected leader, sending a full tablet report...
I20260812 06:20:07.422868 17166 catalog_manager.cc:5719] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151 reported cstate change: term changed from 0 to 1, leader changed from <none> to 2a2efc160a0e4126baddd04ff2e4c151 (127.16.183.1). New cstate: current_term: 1 leader_uuid: "2a2efc160a0e4126baddd04ff2e4c151" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2a2efc160a0e4126baddd04ff2e4c151" member_type: VOTER last_known_addr { host: "127.16.183.1" port: 36263 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:07.490947 17116 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.060s	user 0.017s	sys 0.012s
I20260812 06:20:07.610491 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushMRSOp(dab500ab3095440f979c37253414e157): perf score=15.086190
I20260812 06:20:07.755724 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushMRSOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.145s	user 0.113s	sys 0.032s Metrics: {"bytes_written":8820441,"cfile_init":1,"compiler_manager_pool.queue_time_us":259,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":200,"dirs.run_wall_time_us":1850,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35277,"lbm_writes_lt_1ms":572,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":268672,"thread_start_us":140,"threads_started":1,"update_count":1075}
I20260812 06:20:07.756878 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling LogGCOp(dab500ab3095440f979c37253414e157): free 8725963 bytes of WAL
I20260812 06:20:07.757202 17296 log_reader.cc:385] T dab500ab3095440f979c37253414e157: removed 1 log segments from log reader
I20260812 06:20:07.757277 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000001 (ops 1-6)
I20260812 06:20:07.759999 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: LogGCOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:07.760504 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:07.779029 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.018s	user 0.005s	sys 0.009s Metrics: {"bytes_written":3487280,"delete_count":0,"lbm_write_time_us":5493,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:20:07.779659 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:07.898258 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.118s	user 0.081s	sys 0.037s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528884,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":901,"lbm_read_time_us":7710,"lbm_reads_lt_1ms":364,"lbm_write_time_us":20679,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"thread_start_us":317,"threads_started":5,"update_count":1500}
I20260812 06:20:07.898928 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=10.126437
I20260812 06:20:07.948814 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.050s	user 0.020s	sys 0.023s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20450,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.949313 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:07.960598 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4230,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.961304 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:08.085718 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.124s	user 0.078s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":714,"lbm_read_time_us":8281,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24434,"lbm_writes_lt_1ms":443,"mutex_wait_us":316,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":42496,"update_count":2000}
I20260812 06:20:08.086369 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=10.126437
I20260812 06:20:08.141611 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.055s	user 0.021s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16012,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:08.142247 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:08.153820 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4490,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.154312 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:08.311901 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.157s	user 0.107s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":276,"lbm_read_time_us":11534,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24549,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:20:08.312659 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=10.126437
I20260812 06:20:08.351751 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.039s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17282,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:08.352227 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:08.456558 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.104s	user 0.090s	sys 0.014s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528782,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":333,"lbm_read_time_us":6087,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19913,"lbm_writes_lt_1ms":343,"mutex_wait_us":30,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":71552,"update_count":1500}
I20260812 06:20:08.457130 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling UndoDeltaBlockGCOp(dab500ab3095440f979c37253414e157): 12308959 bytes on disk
I20260812 06:20:08.457687 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: UndoDeltaBlockGCOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:20:08.458107 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=10.126437
I20260812 06:20:08.490785 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.033s	user 0.022s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14418,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:08.491245 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:08.600915 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.109s	user 0.078s	sys 0.031s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":366,"lbm_read_time_us":6910,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19882,"lbm_writes_lt_1ms":343,"mutex_wait_us":49,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":1500}
I20260812 06:20:08.601603 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=10.126437
I20260812 06:20:08.640301 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.038s	user 0.025s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17225,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:08.640985 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:08.657465 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6423,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.657963 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:08.786624 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.128s	user 0.108s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":643,"lbm_read_time_us":8615,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26696,"lbm_writes_lt_1ms":443,"mutex_wait_us":305,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:20:08.787495 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=10.126437
I20260812 06:20:08.834967 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.047s	user 0.021s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16312,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:08.835532 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:08.846690 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4305,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.847465 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:08.974361 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.127s	user 0.102s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":664,"lbm_read_time_us":9867,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23781,"lbm_writes_lt_1ms":443,"mutex_wait_us":289,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.975178 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=10.126437
I20260812 06:20:09.017359 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.042s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15124,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:09.017859 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:09.029842 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4435,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.030597 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushMRSOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:09.064008 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushMRSOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":74,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1813,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:09.064810 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling LogGCOp(dab500ab3095440f979c37253414e157): free 124257234 bytes of WAL
I20260812 06:20:09.065059 17296 log_reader.cc:385] T dab500ab3095440f979c37253414e157: removed 12 log segments from log reader
I20260812 06:20:09.065101 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000002 (ops 7-11)
I20260812 06:20:09.065132 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000003 (ops 12-16)
I20260812 06:20:09.065196 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000004 (ops 17-21)
I20260812 06:20:09.065235 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000005 (ops 22-26)
I20260812 06:20:09.065277 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000006 (ops 27-30)
I20260812 06:20:09.065326 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000007 (ops 31-35)
I20260812 06:20:09.065363 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000008 (ops 36-40)
I20260812 06:20:09.065428 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000009 (ops 41-45)
I20260812 06:20:09.065466 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000010 (ops 46-50)
I20260812 06:20:09.065506 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000011 (ops 51-55)
I20260812 06:20:09.065546 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000012 (ops 56-60)
I20260812 06:20:09.065588 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000013 (ops 61-65)
I20260812 06:20:09.097496 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: LogGCOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:09.098105 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling UndoDeltaBlockGCOp(dab500ab3095440f979c37253414e157): 463 bytes on disk
I20260812 06:20:09.098690 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: UndoDeltaBlockGCOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:20:09.099354 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=3.181125
I20260812 06:20:09.111899 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4878,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:09.112389 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:09.122666 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3701,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:09.123320 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:09.293390 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.170s	user 0.121s	sys 0.045s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836360,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":625,"lbm_read_time_us":12168,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33777,"lbm_writes_lt_1ms":643,"mutex_wait_us":75,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16000,"thread_start_us":86,"threads_started":1,"update_count":3000}
I20260812 06:20:09.294067 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=14.095187
I20260812 06:20:09.354084 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.060s	user 0.025s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26758,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.354667 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:09.371665 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5764,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.372387 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:09.542770 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.170s	user 0.118s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":343,"lbm_read_time_us":10717,"lbm_reads_lt_1ms":568,"lbm_write_time_us":32406,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":102144,"update_count":2500}
I20260812 06:20:09.543545 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=14.095187
I20260812 06:20:09.611979 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.068s	user 0.036s	sys 0.018s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23096,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.612548 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:09.625350 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4405,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.625895 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:09.808498 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.182s	user 0.132s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1010,"lbm_read_time_us":10792,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32615,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:20:09.809218 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=14.095187
I20260812 06:20:09.865688 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.056s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21659,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.866346 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:09.877769 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4500,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.878306 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:10.057790 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.179s	user 0.098s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":890,"lbm_read_time_us":13395,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31691,"lbm_writes_lt_1ms":543,"mutex_wait_us":72,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2500}
I20260812 06:20:10.058521 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=14.095187
I20260812 06:20:10.121032 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.062s	user 0.020s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21093,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.121661 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:10.132808 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4383,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.133279 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:10.320118 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.187s	user 0.109s	sys 0.075s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":237,"lbm_read_time_us":13382,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31882,"lbm_writes_lt_1ms":543,"mutex_wait_us":69,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2500}
I20260812 06:20:10.320995 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=11.118625
I20260812 06:20:10.360353 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.039s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16766,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:10.361181 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:10.375856 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5105,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:10.376327 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:10.539047 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.163s	user 0.114s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":879,"lbm_read_time_us":9522,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24458,"lbm_writes_lt_1ms":443,"mutex_wait_us":302,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2000}
I20260812 06:20:10.539606 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=11.118625
I20260812 06:20:10.568894 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.029s	user 0.023s	sys 0.005s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":12831,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:10.569701 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:10.587692 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.018s	user 0.002s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4993,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:10.588311 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushMRSOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:10.628685 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushMRSOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.040s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":1225,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2384,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:10.629734 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling UndoDeltaBlockGCOp(dab500ab3095440f979c37253414e157): 482 bytes on disk
I20260812 06:20:10.630112 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: UndoDeltaBlockGCOp(dab500ab3095440f979c37253414e157) 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:20:10.630590 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=3.181125
I20260812 06:20:10.642156 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.011s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4512,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:10.642637 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling LogGCOp(dab500ab3095440f979c37253414e157): free 133024316 bytes of WAL
I20260812 06:20:10.642858 17296 log_reader.cc:385] T dab500ab3095440f979c37253414e157: removed 13 log segments from log reader
I20260812 06:20:10.642902 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000014 (ops 66-70)
I20260812 06:20:10.642933 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000015 (ops 71-75)
I20260812 06:20:10.642993 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000016 (ops 76-80)
I20260812 06:20:10.643025 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000017 (ops 81-85)
I20260812 06:20:10.643066 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000018 (ops 86-90)
I20260812 06:20:10.643123 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000019 (ops 91-95)
I20260812 06:20:10.643163 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000020 (ops 96-100)
I20260812 06:20:10.643203 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000021 (ops 101-104)
I20260812 06:20:10.643242 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000022 (ops 105-109)
I20260812 06:20:10.643280 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000023 (ops 110-114)
I20260812 06:20:10.643318 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000024 (ops 115-119)
I20260812 06:20:10.643361 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000025 (ops 120-124)
I20260812 06:20:10.643438 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000026 (ops 125-129)
I20260812 06:20:10.673604 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: LogGCOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:10.674046 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=3.181125
I20260812 06:20:10.687883 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4841094,"delete_count":0,"lbm_write_time_us":5494,"lbm_writes_lt_1ms":121,"reinsert_count":0,"update_count":590}
I20260812 06:20:10.688421 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=1.196750
I20260812 06:20:10.708146 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.020s	user 0.006s	sys 0.012s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":2981,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:20:10.708779 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:10.958951 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.250s	user 0.191s	sys 0.049s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32938869,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":576,"lbm_read_time_us":16204,"lbm_reads_lt_1ms":775,"lbm_write_time_us":41320,"lbm_writes_lt_1ms":743,"mutex_wait_us":366,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6016,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:20:10.959635 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=18.063937
I20260812 06:20:11.029045 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.068s	user 0.035s	sys 0.028s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":28440,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:11.029577 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:11.042443 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4621,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.043149 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:11.244746 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.201s	user 0.137s	sys 0.063s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836140,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1121,"lbm_read_time_us":13764,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37974,"lbm_writes_lt_1ms":643,"mutex_wait_us":469,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:20:11.245355 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=14.095187
I20260812 06:20:11.302138 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.057s	user 0.021s	sys 0.033s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27088,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.302701 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:11.314690 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.012s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4713,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.315196 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:11.508486 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.193s	user 0.119s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":607,"lbm_read_time_us":14207,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34040,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22912,"update_count":2500}
I20260812 06:20:11.509227 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=14.095187
I20260812 06:20:11.570926 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.062s	user 0.022s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22173,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.571765 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:11.587828 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.016s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6079,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.588347 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:11.769374 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.181s	user 0.119s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":697,"lbm_read_time_us":13590,"lbm_reads_lt_1ms":568,"lbm_write_time_us":30301,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2500}
I20260812 06:20:11.770179 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=14.095187
I20260812 06:20:11.829392 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.059s	user 0.025s	sys 0.032s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":21975,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.830036 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:11.843082 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4813,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.843742 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:12.039068 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.195s	user 0.129s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733719,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":363,"lbm_read_time_us":12829,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34557,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:20:12.040035 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=14.095187
I20260812 06:20:12.094398 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.054s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20180,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:12.095078 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:12.116598 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.021s	user 0.006s	sys 0.014s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4407,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.117189 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushMRSOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:12.151765 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushMRSOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.034s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":299,"dirs.run_wall_time_us":1412,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1711,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:12.152657 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling LogGCOp(dab500ab3095440f979c37253414e157): free 112239614 bytes of WAL
I20260812 06:20:12.152945 17296 log_reader.cc:385] T dab500ab3095440f979c37253414e157: removed 11 log segments from log reader
I20260812 06:20:12.153013 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000027 (ops 130-134)
I20260812 06:20:12.153056 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000028 (ops 135-139)
I20260812 06:20:12.153091 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000029 (ops 140-144)
I20260812 06:20:12.153121 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000030 (ops 145-149)
I20260812 06:20:12.153146 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000031 (ops 150-154)
I20260812 06:20:12.153178 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000032 (ops 155-158)
I20260812 06:20:12.153213 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000033 (ops 159-163)
I20260812 06:20:12.153247 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000034 (ops 164-168)
I20260812 06:20:12.153275 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000035 (ops 169-173)
I20260812 06:20:12.153301 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000036 (ops 174-178)
I20260812 06:20:12.153329 17296 log.cc:1079] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/dab500ab3095440f979c37253414e157/wal-000000037 (ops 179-183)
I20260812 06:20:12.182353 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: LogGCOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:12.182931 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling UndoDeltaBlockGCOp(dab500ab3095440f979c37253414e157): 447 bytes on disk
I20260812 06:20:12.183645 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: UndoDeltaBlockGCOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":121,"lbm_reads_lt_1ms":4}
I20260812 06:20:12.184342 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:12.198113 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.014s	user 0.011s	sys 0.000s 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:20:12.198695 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:12.415824 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.217s	user 0.146s	sys 0.061s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836255,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1241,"lbm_read_time_us":14545,"lbm_reads_lt_1ms":665,"lbm_write_time_us":38309,"lbm_writes_lt_1ms":643,"mutex_wait_us":640,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11648,"thread_start_us":97,"threads_started":1,"update_count":3000}
I20260812 06:20:12.416487 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=18.063937
I20260812 06:20:12.491724 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.075s	user 0.052s	sys 0.016s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":31295,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:12.492506 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157): perf score=2.188937
I20260812 06:20:12.505049 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: FlushDeltaMemStoresOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4651,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.505926 17415 maintenance_manager.cc:419] P 2a2efc160a0e4126baddd04ff2e4c151: Scheduling MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157): perf score=1.000000
I20260812 06:20:12.596853 17116 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.106s	user 1.822s	sys 0.134s
I20260812 06:20:12.666376 17116 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.069s	user 0.001s	sys 0.000s
I20260812 06:20:12.667052 17116 tablet_server.cc:179] TabletServer@127.16.183.1:0 shutting down...
I20260812 06:20:12.686852 17296 maintenance_manager.cc:643] P 2a2efc160a0e4126baddd04ff2e4c151: MajorDeltaCompactionOp(dab500ab3095440f979c37253414e157) complete. Timing: real 0.181s	user 0.125s	sys 0.055s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836138,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":348,"lbm_read_time_us":15028,"lbm_reads_lt_1ms":668,"lbm_write_time_us":32205,"lbm_writes_lt_1ms":643,"mutex_wait_us":29,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:20:12.687623 17116 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:12.688067 17116 tablet_replica.cc:333] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151: stopping tablet replica
I20260812 06:20:12.688314 17116 raft_consensus.cc:2243] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:12.688571 17116 raft_consensus.cc:2272] T dab500ab3095440f979c37253414e157 P 2a2efc160a0e4126baddd04ff2e4c151 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:12.719333 17116 tablet_server.cc:196] TabletServer@127.16.183.1:0 shutdown complete.
I20260812 06:20:12.741106 17116 master.cc:562] Master@127.16.183.62:33299 shutting down...
I20260812 06:20:12.745707 17116 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:12.745947 17116 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:12.746045 17116 tablet_replica.cc:333] T 00000000000000000000000000000000 P e6cb55b52e0f45c0b2f68fdc05977d42: stopping tablet replica
I20260812 06:20:12.758971 17116 master.cc:584] Master@127.16.183.62:33299 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5658 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:12.855625 17116 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.16.183.62:40581
I20260812 06:20:12.856137 17116 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:12.858186 17470 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:12.858183 17473 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:12.858184 17466 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:12.858428 17116 server_base.cc:1061] running on GCE node
I20260812 06:20:12.858619 17116 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:12.858691 17116 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:12.858718 17116 hybrid_clock.cc:648] HybridClock initialized: now 1786515612858717 us; error 0 us; skew 500 ppm
I20260812 06:20:12.859642 17116 webserver.cc:533] Webserver started at http://127.16.183.62:43667/ using document root <none> and password file <none>
I20260812 06:20:12.859817 17116 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:12.859885 17116 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:12.859988 17116 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:12.860414 17116 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/master-0-root/instance:
uuid: "979794663d84451b9253353d2e28107b"
format_stamp: "Formatted at 2026-08-12 06:20:12 on dist-test-slave-gw5c"
I20260812 06:20:12.862008 17116 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:12.863101 17480 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:12.863353 17116 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:12.863469 17116 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/master-0-root
uuid: "979794663d84451b9253353d2e28107b"
format_stamp: "Formatted at 2026-08-12 06:20:12 on dist-test-slave-gw5c"
I20260812 06:20:12.863562 17116 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-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:20:12.871307 17116 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:12.871797 17116 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:12.876331 17116 rpc_server.cc:307] RPC server started. Bound to: 127.16.183.62:40581
I20260812 06:20:12.878669 17576 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.183.62:40581 every 8 connection(s)
I20260812 06:20:12.881009 17577 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:20:12.886068 17577 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b: Bootstrap starting.
I20260812 06:20:12.886894 17577 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:12.888070 17577 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b: No bootstrap required, opened a new log
I20260812 06:20:12.888461 17577 raft_consensus.cc:359] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "979794663d84451b9253353d2e28107b" member_type: VOTER }
I20260812 06:20:12.888553 17577 raft_consensus.cc:385] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:12.888583 17577 raft_consensus.cc:740] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 979794663d84451b9253353d2e28107b, State: Initialized, Role: FOLLOWER
I20260812 06:20:12.888711 17577 consensus_queue.cc:260] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [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: "979794663d84451b9253353d2e28107b" member_type: VOTER }
I20260812 06:20:12.888765 17577 raft_consensus.cc:399] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:12.888836 17577 raft_consensus.cc:493] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:12.888901 17577 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:12.889638 17577 raft_consensus.cc:515] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "979794663d84451b9253353d2e28107b" member_type: VOTER }
I20260812 06:20:12.889801 17577 leader_election.cc:304] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [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: 979794663d84451b9253353d2e28107b; no voters: 
I20260812 06:20:12.890007 17577 leader_election.cc:290] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:12.890147 17582 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:12.890388 17582 raft_consensus.cc:697] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [term 1 LEADER]: Becoming Leader. State: Replica: 979794663d84451b9253353d2e28107b, State: Running, Role: LEADER
I20260812 06:20:12.890547 17577 sys_catalog.cc:565] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:12.890544 17582 consensus_queue.cc:237] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [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: "979794663d84451b9253353d2e28107b" member_type: VOTER }
I20260812 06:20:12.891078 17584 sys_catalog.cc:455] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [sys.catalog]: SysCatalogTable state changed. Reason: New leader 979794663d84451b9253353d2e28107b. Latest consensus state: current_term: 1 leader_uuid: "979794663d84451b9253353d2e28107b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "979794663d84451b9253353d2e28107b" member_type: VOTER } }
I20260812 06:20:12.891059 17583 sys_catalog.cc:455] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "979794663d84451b9253353d2e28107b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "979794663d84451b9253353d2e28107b" member_type: VOTER } }
I20260812 06:20:12.891204 17584 sys_catalog.cc:458] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:12.891278 17583 sys_catalog.cc:458] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:12.891845 17595 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:12.892762 17595 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:12.892947 17116 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:12.894680 17595 catalog_manager.cc:1383] Generated new cluster ID: d41b134e9db54bc39d72aa528145cb3d
I20260812 06:20:12.894748 17595 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:12.913017 17595 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:12.913642 17595 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:12.920974 17595 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b: Generated new TSK 0
I20260812 06:20:12.921178 17595 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:12.925551 17116 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:12.927603 17613 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:20:12.927603 17615 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:12.927649 17617 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:12.927867 17116 server_base.cc:1061] running on GCE node
I20260812 06:20:12.928085 17116 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:12.928131 17116 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:12.928148 17116 hybrid_clock.cc:648] HybridClock initialized: now 1786515612928148 us; error 0 us; skew 500 ppm
I20260812 06:20:12.929132 17116 webserver.cc:533] Webserver started at http://127.16.183.1:45015/ using document root <none> and password file <none>
I20260812 06:20:12.929324 17116 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:12.929375 17116 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:12.929459 17116 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:12.929904 17116 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/instance:
uuid: "a97e226147814ec4b74cc4452ea1c252"
format_stamp: "Formatted at 2026-08-12 06:20:12 on dist-test-slave-gw5c"
I20260812 06:20:12.931609 17116 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:12.932641 17626 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:12.932905 17116 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:12.932972 17116 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root
uuid: "a97e226147814ec4b74cc4452ea1c252"
format_stamp: "Formatted at 2026-08-12 06:20:12 on dist-test-slave-gw5c"
I20260812 06:20:12.933074 17116 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-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:12.954110 17116 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:12.954588 17116 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:12.954970 17116 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:12.955543 17116 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:12.955585 17116 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:12.955621 17116 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:12.955636 17116 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:12.960542 17116 rpc_server.cc:307] RPC server started. Bound to: 127.16.183.1:32943
I20260812 06:20:12.961874 17740 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.183.1:32943 every 8 connection(s)
I20260812 06:20:12.973572 17747 heartbeater.cc:344] Connected to a master server at 127.16.183.62:40581
I20260812 06:20:12.973762 17747 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:12.974084 17747 heartbeater.cc:507] Master 127.16.183.62:40581 requested a full tablet report, sending...
I20260812 06:20:12.975189 17507 ts_manager.cc:194] Registered new tserver with Master: a97e226147814ec4b74cc4452ea1c252 (127.16.183.1:32943)
I20260812 06:20:12.976127 17116 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014599731s
I20260812 06:20:12.976131 17507 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54876
I20260812 06:20:12.984321 17507 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54882:
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:12.994400 17681 tablet_service.cc:1511] Processing CreateTablet for tablet 7ba8e1b8adce4832948fe03e96c3a108 (DEFAULT_TABLE table=heavy-update-compaction-test [id=fb7436e9688b419abaa92acd8d39baa9]), partition=
I20260812 06:20:12.994733 17681 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 7ba8e1b8adce4832948fe03e96c3a108. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:12.996961 17766 tablet_bootstrap.cc:492] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Bootstrap starting.
I20260812 06:20:12.997888 17766 tablet_bootstrap.cc:654] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:12.999101 17766 tablet_bootstrap.cc:492] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: No bootstrap required, opened a new log
I20260812 06:20:12.999222 17766 ts_tablet_manager.cc:1403] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:12.999779 17766 raft_consensus.cc:359] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a97e226147814ec4b74cc4452ea1c252" member_type: VOTER last_known_addr { host: "127.16.183.1" port: 32943 } }
I20260812 06:20:12.999902 17766 raft_consensus.cc:385] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:12.999948 17766 raft_consensus.cc:740] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a97e226147814ec4b74cc4452ea1c252, State: Initialized, Role: FOLLOWER
I20260812 06:20:13.000113 17766 consensus_queue.cc:260] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252 [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: "a97e226147814ec4b74cc4452ea1c252" member_type: VOTER last_known_addr { host: "127.16.183.1" port: 32943 } }
I20260812 06:20:13.000226 17766 raft_consensus.cc:399] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:13.000275 17766 raft_consensus.cc:493] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:13.000327 17766 raft_consensus.cc:3060] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:13.001091 17766 raft_consensus.cc:515] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a97e226147814ec4b74cc4452ea1c252" member_type: VOTER last_known_addr { host: "127.16.183.1" port: 32943 } }
I20260812 06:20:13.001214 17766 leader_election.cc:304] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252 [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: a97e226147814ec4b74cc4452ea1c252; no voters: 
I20260812 06:20:13.001392 17766 leader_election.cc:290] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:13.001547 17769 raft_consensus.cc:2804] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:13.001701 17766 ts_tablet_manager.cc:1434] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:20:13.001709 17747 heartbeater.cc:499] Master 127.16.183.62:40581 was elected leader, sending a full tablet report...
I20260812 06:20:13.001781 17769 raft_consensus.cc:697] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252 [term 1 LEADER]: Becoming Leader. State: Replica: a97e226147814ec4b74cc4452ea1c252, State: Running, Role: LEADER
I20260812 06:20:13.001924 17769 consensus_queue.cc:237] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252 [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: "a97e226147814ec4b74cc4452ea1c252" member_type: VOTER last_known_addr { host: "127.16.183.1" port: 32943 } }
I20260812 06:20:13.003213 17507 catalog_manager.cc:5719] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252 reported cstate change: term changed from 0 to 1, leader changed from <none> to a97e226147814ec4b74cc4452ea1c252 (127.16.183.1). New cstate: current_term: 1 leader_uuid: "a97e226147814ec4b74cc4452ea1c252" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a97e226147814ec4b74cc4452ea1c252" member_type: VOTER last_known_addr { host: "127.16.183.1" port: 32943 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:13.067711 17116 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.011s	sys 0.013s
I20260812 06:20:13.212373 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushMRSOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=15.086190
I20260812 06:20:13.344223 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushMRSOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.132s	user 0.102s	sys 0.028s Metrics: {"bytes_written":9558873,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":243,"dirs.run_wall_time_us":740,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":30673,"lbm_writes_lt_1ms":590,"mutex_wait_us":352,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"update_count":1165}
I20260812 06:20:13.345228 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling LogGCOp(7ba8e1b8adce4832948fe03e96c3a108): free 11976772 bytes of WAL
I20260812 06:20:13.345587 17635 log_reader.cc:385] T 7ba8e1b8adce4832948fe03e96c3a108: removed 1 log segments from log reader
I20260812 06:20:13.345669 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000001 (ops 1-6)
I20260812 06:20:13.349053 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: LogGCOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:13.349514 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.196750
I20260812 06:20:13.359851 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":2748830,"delete_count":0,"lbm_write_time_us":3824,"lbm_writes_lt_1ms":70,"reinsert_count":0,"update_count":335}
I20260812 06:20:13.360293 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:13.498374 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.138s	user 0.085s	sys 0.053s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528866,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":705,"lbm_read_time_us":10192,"lbm_reads_lt_1ms":368,"lbm_write_time_us":21672,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":10624,"thread_start_us":338,"threads_started":5,"update_count":1500}
I20260812 06:20:13.499151 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling UndoDeltaBlockGCOp(7ba8e1b8adce4832948fe03e96c3a108): 12308959 bytes on disk
I20260812 06:20:13.499781 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: UndoDeltaBlockGCOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":104,"lbm_reads_lt_1ms":4}
I20260812 06:20:13.500427 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=10.126437
I20260812 06:20:13.546483 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.046s	user 0.029s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17534,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.546988 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:13.558063 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4063,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.558784 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:13.687775 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.129s	user 0.100s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":923,"lbm_read_time_us":8117,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24212,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":28672,"update_count":2000}
I20260812 06:20:13.688511 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=10.126437
I20260812 06:20:13.733798 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.045s	user 0.018s	sys 0.022s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18241,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.734381 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:13.750998 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6085,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.751740 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:13.882591 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.131s	user 0.102s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631310,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":178,"lbm_read_time_us":9180,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26053,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2000}
I20260812 06:20:13.883296 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=10.126437
I20260812 06:20:13.925282 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.042s	user 0.014s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13193,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.925964 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:13.937146 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.011s	user 0.006s	sys 0.000s Metrics: {"bytes_written":1395006,"delete_count":0,"lbm_write_time_us":2212,"lbm_writes_lt_1ms":37,"reinsert_count":0,"update_count":170}
I20260812 06:20:13.937656 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.196750
I20260812 06:20:13.946040 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.008s	user 0.004s	sys 0.002s Metrics: {"bytes_written":2707805,"delete_count":0,"lbm_write_time_us":3102,"lbm_writes_lt_1ms":69,"reinsert_count":0,"update_count":330}
I20260812 06:20:13.946522 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:14.098358 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.152s	user 0.096s	sys 0.056s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20631337,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":253,"lbm_read_time_us":10739,"lbm_reads_lt_1ms":473,"lbm_write_time_us":23211,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2000}
I20260812 06:20:14.099160 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=10.126437
I20260812 06:20:14.141911 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.042s	user 0.018s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18498,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":1500}
I20260812 06:20:14.142684 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:14.159936 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.017s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6637,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.160511 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:14.298269 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.138s	user 0.093s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1190,"lbm_read_time_us":10690,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26759,"lbm_writes_lt_1ms":443,"mutex_wait_us":321,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:20:14.298920 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=10.126437
I20260812 06:20:14.344095 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.045s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":20986,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.345149 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:14.373647 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.028s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6085,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.374493 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:14.386547 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4633,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.387292 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:14.548810 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.161s	user 0.117s	sys 0.042s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733841,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":219,"lbm_read_time_us":11165,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34161,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2500}
I20260812 06:20:14.549516 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=11.118625
I20260812 06:20:14.585292 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.036s	user 0.013s	sys 0.021s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15618,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:14.586009 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:14.603302 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6350,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:14.603820 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushMRSOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:14.629467 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushMRSOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.025s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1129,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1438,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:14.630061 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling LogGCOp(7ba8e1b8adce4832948fe03e96c3a108): free 121006432 bytes of WAL
I20260812 06:20:14.630286 17635 log_reader.cc:385] T 7ba8e1b8adce4832948fe03e96c3a108: removed 12 log segments from log reader
I20260812 06:20:14.630354 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000002 (ops 7-11)
I20260812 06:20:14.630409 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000003 (ops 12-16)
I20260812 06:20:14.630470 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000004 (ops 17-20)
I20260812 06:20:14.630510 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000005 (ops 21-25)
I20260812 06:20:14.630546 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000006 (ops 26-30)
I20260812 06:20:14.630584 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000007 (ops 31-35)
I20260812 06:20:14.630620 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000008 (ops 36-40)
I20260812 06:20:14.630761 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000009 (ops 41-45)
I20260812 06:20:14.630861 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000010 (ops 46-50)
I20260812 06:20:14.630904 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000011 (ops 51-55)
I20260812 06:20:14.630945 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000012 (ops 56-60)
I20260812 06:20:14.630985 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000013 (ops 61-65)
I20260812 06:20:14.657006 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: LogGCOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:14.657456 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling UndoDeltaBlockGCOp(7ba8e1b8adce4832948fe03e96c3a108): 462 bytes on disk
I20260812 06:20:14.657899 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: UndoDeltaBlockGCOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:20:14.658406 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=5.165500
I20260812 06:20:14.678650 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.020s	user 0.014s	sys 0.005s Metrics: {"bytes_written":7056402,"delete_count":0,"lbm_write_time_us":7966,"lbm_writes_lt_1ms":175,"reinsert_count":0,"update_count":860}
I20260812 06:20:14.679183 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:14.684912 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.006s	user 0.004s	sys 0.000s Metrics: {"bytes_written":1148852,"delete_count":0,"lbm_write_time_us":1432,"lbm_writes_lt_1ms":31,"reinsert_count":0,"update_count":140}
I20260812 06:20:14.685509 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:14.860522 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.175s	user 0.131s	sys 0.043s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836296,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":178,"lbm_read_time_us":13517,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34630,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20096,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:20:14.861299 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=14.095187
I20260812 06:20:14.923326 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.062s	user 0.034s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25576,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:14.924100 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:14.944778 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.020s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6615,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.945240 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:15.102861 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.157s	user 0.115s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":655,"lbm_read_time_us":10122,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28845,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2500}
I20260812 06:20:15.103623 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=14.095187
I20260812 06:20:15.156950 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.053s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21882,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.157450 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:15.303716 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.146s	user 0.085s	sys 0.051s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":109,"lbm_read_time_us":9859,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22957,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2000}
I20260812 06:20:15.304368 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=14.095187
I20260812 06:20:15.356209 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.052s	user 0.031s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21064,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.356763 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:15.368683 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4573,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.369375 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:15.579103 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.210s	user 0.129s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":331,"lbm_read_time_us":16799,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32170,"lbm_writes_lt_1ms":543,"mutex_wait_us":65,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:20:15.579780 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=14.095187
I20260812 06:20:15.628258 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.048s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20915,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.628747 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:15.641426 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4490,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.642639 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:15.809718 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.167s	user 0.121s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":902,"lbm_read_time_us":10700,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29187,"lbm_writes_lt_1ms":543,"mutex_wait_us":75,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:20:15.810487 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=14.095187
I20260812 06:20:15.861380 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.051s	user 0.040s	sys 0.007s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21489,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.861896 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:15.873994 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4334,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.875541 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:16.029376 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.154s	user 0.125s	sys 0.021s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":309,"lbm_read_time_us":9723,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29368,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27648,"update_count":2500}
I20260812 06:20:16.030032 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=14.095187
I20260812 06:20:16.080225 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.050s	user 0.034s	sys 0.015s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":22842,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.080822 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:16.092708 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4282,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.093376 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushMRSOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:16.128176 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushMRSOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.035s	user 0.033s	sys 0.001s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1128,"drs_written":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2063,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:16.128899 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling LogGCOp(7ba8e1b8adce4832948fe03e96c3a108): free 124257255 bytes of WAL
I20260812 06:20:16.129173 17635 log_reader.cc:385] T 7ba8e1b8adce4832948fe03e96c3a108: removed 12 log segments from log reader
I20260812 06:20:16.129232 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000014 (ops 66-70)
I20260812 06:20:16.129272 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000015 (ops 71-75)
I20260812 06:20:16.129309 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000016 (ops 76-80)
I20260812 06:20:16.129333 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000017 (ops 81-85)
I20260812 06:20:16.129355 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000018 (ops 86-90)
I20260812 06:20:16.129384 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000019 (ops 91-94)
I20260812 06:20:16.129413 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000020 (ops 95-99)
I20260812 06:20:16.129448 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000021 (ops 100-104)
I20260812 06:20:16.129482 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000022 (ops 105-109)
I20260812 06:20:16.129511 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000023 (ops 110-114)
I20260812 06:20:16.129540 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000024 (ops 115-119)
I20260812 06:20:16.129570 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000025 (ops 120-124)
I20260812 06:20:16.162796 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: LogGCOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.034s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:16.163275 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling UndoDeltaBlockGCOp(7ba8e1b8adce4832948fe03e96c3a108): 472 bytes on disk
I20260812 06:20:16.163997 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: UndoDeltaBlockGCOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:20:16.164633 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:16.185842 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.021s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6733,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.186327 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:16.197301 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4245,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.197813 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:16.446712 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.249s	user 0.151s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938780,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":257,"lbm_read_time_us":15133,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41676,"lbm_writes_lt_1ms":743,"mutex_wait_us":23,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16000,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:20:16.447535 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=18.063937
I20260812 06:20:16.517335 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.070s	user 0.046s	sys 0.017s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":28204,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:16.518059 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:16.533066 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5889,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.533593 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:16.741264 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.207s	user 0.140s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836139,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":302,"lbm_read_time_us":14932,"lbm_reads_lt_1ms":664,"lbm_write_time_us":37345,"lbm_writes_lt_1ms":643,"mutex_wait_us":46,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":3000}
I20260812 06:20:16.741916 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=14.095187
I20260812 06:20:16.798683 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.057s	user 0.024s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24803,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.799276 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:16.810657 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4557,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.811136 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:17.004583 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.193s	user 0.125s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":198,"lbm_read_time_us":14039,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29299,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:20:17.005229 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=14.095187
I20260812 06:20:17.073179 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.068s	user 0.028s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23289,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.073766 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:17.085321 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4578,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.085888 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:17.273021 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.187s	user 0.143s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":217,"lbm_read_time_us":13940,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32143,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:17.273656 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=11.118625
I20260812 06:20:17.318488 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.045s	user 0.016s	sys 0.025s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18926,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:17.319243 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:17.345585 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.026s	user 0.006s	sys 0.016s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5149,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:17.346272 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:17.521894 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.175s	user 0.110s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631304,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":797,"lbm_read_time_us":11437,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27941,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":39296,"update_count":2000}
I20260812 06:20:17.522663 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=14.095187
I20260812 06:20:17.574741 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.052s	user 0.016s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25407,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.575333 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:17.597011 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.021s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:20:17.597618 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushMRSOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:17.656355 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushMRSOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.059s	user 0.030s	sys 0.005s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":97,"dirs.run_cpu_time_us":459,"dirs.run_wall_time_us":1425,"drs_written":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2287,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:17.657327 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling LogGCOp(7ba8e1b8adce4832948fe03e96c3a108): free 112239534 bytes of WAL
I20260812 06:20:17.657644 17635 log_reader.cc:385] T 7ba8e1b8adce4832948fe03e96c3a108: removed 11 log segments from log reader
I20260812 06:20:17.657721 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000026 (ops 125-129)
I20260812 06:20:17.657778 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000027 (ops 130-134)
I20260812 06:20:17.657835 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000028 (ops 135-139)
I20260812 06:20:17.657881 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000029 (ops 140-144)
I20260812 06:20:17.657920 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000030 (ops 145-149)
I20260812 06:20:17.657959 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000031 (ops 150-154)
I20260812 06:20:17.657999 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000032 (ops 155-158)
I20260812 06:20:17.658039 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000033 (ops 159-163)
I20260812 06:20:17.658080 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000034 (ops 164-168)
I20260812 06:20:17.658121 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000035 (ops 169-173)
I20260812 06:20:17.658161 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000036 (ops 174-178)
I20260812 06:20:17.684765 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: LogGCOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:17.690781 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=7.149875
I20260812 06:20:17.714731 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.024s	user 0.007s	sys 0.013s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":10012,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:17.715446 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling LogGCOp(7ba8e1b8adce4832948fe03e96c3a108): free 8767140 bytes of WAL
I20260812 06:20:17.715706 17635 log_reader.cc:385] T 7ba8e1b8adce4832948fe03e96c3a108: removed 1 log segments from log reader
I20260812 06:20:17.715786 17635 log.cc:1079] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: Deleting log segment in path: /tmp/dist-test-taskJ3zk9K/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515607186276-17116-0/minicluster-data/ts-0-root/wals/7ba8e1b8adce4832948fe03e96c3a108/wal-000000037 (ops 179-183)
I20260812 06:20:17.717660 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: LogGCOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:17.718043 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:17.729210 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3856,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:17.729894 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling UndoDeltaBlockGCOp(7ba8e1b8adce4832948fe03e96c3a108): 448 bytes on disk
I20260812 06:20:17.730448 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: UndoDeltaBlockGCOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4}
I20260812 06:20:17.731002 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:17.990825 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.260s	user 0.182s	sys 0.073s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37041189,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3991,"lbm_read_time_us":19672,"lbm_reads_lt_1ms":874,"lbm_write_time_us":43599,"lbm_writes_lt_1ms":843,"mutex_wait_us":40,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":4864,"thread_start_us":88,"threads_started":1,"update_count":4000}
I20260812 06:20:17.991756 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=18.063937
I20260812 06:20:18.051600 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.060s	user 0.028s	sys 0.032s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27809,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:18.052161 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=2.188937
I20260812 06:20:18.068856 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: FlushDeltaMemStoresOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.017s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5670,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.069372 17749 maintenance_manager.cc:419] P a97e226147814ec4b74cc4452ea1c252: Scheduling MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108): perf score=1.000000
I20260812 06:20:18.155050 17116 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.087s	user 1.895s	sys 0.118s
I20260812 06:20:18.224830 17116 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.069s	user 0.001s	sys 0.000s
I20260812 06:20:18.225351 17116 tablet_server.cc:179] TabletServer@127.16.183.1:0 shutting down...
I20260812 06:20:18.255595 17635 maintenance_manager.cc:643] P a97e226147814ec4b74cc4452ea1c252: MajorDeltaCompactionOp(7ba8e1b8adce4832948fe03e96c3a108) complete. Timing: real 0.186s	user 0.133s	sys 0.053s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836137,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":447,"lbm_read_time_us":15384,"lbm_reads_lt_1ms":664,"lbm_write_time_us":31507,"lbm_writes_lt_1ms":643,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":27008,"update_count":3000}
I20260812 06:20:18.256332 17116 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:18.256613 17116 tablet_replica.cc:333] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252: stopping tablet replica
I20260812 06:20:18.256750 17116 raft_consensus.cc:2243] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:18.256956 17116 raft_consensus.cc:2272] T 7ba8e1b8adce4832948fe03e96c3a108 P a97e226147814ec4b74cc4452ea1c252 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:18.274706 17116 tablet_server.cc:196] TabletServer@127.16.183.1:0 shutdown complete.
I20260812 06:20:18.308465 17116 master.cc:562] Master@127.16.183.62:40581 shutting down...
I20260812 06:20:18.311901 17116 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:18.312111 17116 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:18.312202 17116 tablet_replica.cc:333] T 00000000000000000000000000000000 P 979794663d84451b9253353d2e28107b: stopping tablet replica
I20260812 06:20:18.324841 17116 master.cc:584] Master@127.16.183.62:40581 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5562 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11222 ms total)

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