[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:54.985342 26876 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.63.62:39175
I20260812 06:19:54.986495 26876 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:54.987159 26876 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:54.994452 26888 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:54.994520 26876 server_base.cc:1061] running on GCE node
W20260812 06:19:54.994437 26885 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:54.994784 26886 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:54.995361 26876 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:54.995515 26876 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:54.995585 26876 hybrid_clock.cc:648] HybridClock initialized: now 1786515594995583 us; error 0 us; skew 500 ppm
I20260812 06:19:54.997575 26876 webserver.cc:533] Webserver started at http://127.26.63.62:35613/ using document root <none> and password file <none>
I20260812 06:19:54.998193 26876 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:54.998283 26876 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:54.998570 26876 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:55.000478 26876 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/master-0-root/instance:
uuid: "9bc4fe4ea1f642fba0e6e2c1b11629f8"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-sb2z"
I20260812 06:19:55.004899 26876 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.003s	sys 0.001s
I20260812 06:19:55.007768 26897 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.009153 26876 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:55.009344 26876 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/master-0-root
uuid: "9bc4fe4ea1f642fba0e6e2c1b11629f8"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-sb2z"
I20260812 06:19:55.009488 26876 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:55.057160 26876 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:55.057943 26876 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:55.058171 26876 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:55.066967 26876 rpc_server.cc:307] RPC server started. Bound to: 127.26.63.62:39175
I20260812 06:19:55.066974 26983 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.63.62:39175 every 8 connection(s)
I20260812 06:19:55.069607 26984 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:55.075464 26984 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8: Bootstrap starting.
I20260812 06:19:55.077991 26984 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:55.079006 26984 log.cc:826] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:55.081261 26984 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8: No bootstrap required, opened a new log
I20260812 06:19:55.084494 26984 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9bc4fe4ea1f642fba0e6e2c1b11629f8" member_type: VOTER }
I20260812 06:19:55.084678 26984 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:55.084751 26984 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9bc4fe4ea1f642fba0e6e2c1b11629f8, State: Initialized, Role: FOLLOWER
I20260812 06:19:55.085431 26984 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [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: "9bc4fe4ea1f642fba0e6e2c1b11629f8" member_type: VOTER }
I20260812 06:19:55.085608 26984 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:55.085691 26984 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:55.085839 26984 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:55.086709 26984 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9bc4fe4ea1f642fba0e6e2c1b11629f8" member_type: VOTER }
I20260812 06:19:55.087194 26984 leader_election.cc:304] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [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: 9bc4fe4ea1f642fba0e6e2c1b11629f8; no voters: 
I20260812 06:19:55.087615 26984 leader_election.cc:290] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:55.087801 26989 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:55.088128 26989 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [term 1 LEADER]: Becoming Leader. State: Replica: 9bc4fe4ea1f642fba0e6e2c1b11629f8, State: Running, Role: LEADER
I20260812 06:19:55.088557 26989 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [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: "9bc4fe4ea1f642fba0e6e2c1b11629f8" member_type: VOTER }
I20260812 06:19:55.088778 26984 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:55.090914 26990 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9bc4fe4ea1f642fba0e6e2c1b11629f8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9bc4fe4ea1f642fba0e6e2c1b11629f8" member_type: VOTER } }
I20260812 06:19:55.090945 26991 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9bc4fe4ea1f642fba0e6e2c1b11629f8. Latest consensus state: current_term: 1 leader_uuid: "9bc4fe4ea1f642fba0e6e2c1b11629f8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9bc4fe4ea1f642fba0e6e2c1b11629f8" member_type: VOTER } }
I20260812 06:19:55.091049 26990 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:55.091055 26991 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:55.091277 26876 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:19:55.093499 27016 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:55.093595 27016 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:55.093685 27015 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:55.094408 27015 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:55.099509 27015 catalog_manager.cc:1383] Generated new cluster ID: 70a4cf231a3b457685a53adf44fd7c5c
I20260812 06:19:55.099629 27015 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:55.117229 27015 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:55.118155 27015 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:55.126399 27015 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8: Generated new TSK 0
I20260812 06:19:55.127130 27015 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:55.156359 26876 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:55.159323 27022 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:55.159415 27025 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:55.159415 27023 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:55.159670 26876 server_base.cc:1061] running on GCE node
I20260812 06:19:55.159859 26876 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:55.159904 26876 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:55.159919 26876 hybrid_clock.cc:648] HybridClock initialized: now 1786515595159919 us; error 0 us; skew 500 ppm
I20260812 06:19:55.160943 26876 webserver.cc:533] Webserver started at http://127.26.63.1:37035/ using document root <none> and password file <none>
I20260812 06:19:55.161144 26876 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:55.161192 26876 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:55.161298 26876 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:55.161727 26876 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/instance:
uuid: "f662dd1ee3b047bf984d9f6e2e48f2b1"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-sb2z"
I20260812 06:19:55.163357 26876 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:55.164439 27032 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.164685 26876 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:55.164760 26876 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root
uuid: "f662dd1ee3b047bf984d9f6e2e48f2b1"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-sb2z"
I20260812 06:19:55.164852 26876 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:55.198496 26876 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:55.199074 26876 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:55.199779 26876 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:55.200737 26876 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:55.200793 26876 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.200867 26876 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:55.200922 26876 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.207741 26876 rpc_server.cc:307] RPC server started. Bound to: 127.26.63.1:44999
I20260812 06:19:55.207850 27127 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.63.1:44999 every 8 connection(s)
I20260812 06:19:55.222606 27128 heartbeater.cc:344] Connected to a master server at 127.26.63.62:39175
I20260812 06:19:55.222884 27128 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:55.223416 27128 heartbeater.cc:507] Master 127.26.63.62:39175 requested a full tablet report, sending...
I20260812 06:19:55.225045 26918 ts_manager.cc:194] Registered new tserver with Master: f662dd1ee3b047bf984d9f6e2e48f2b1 (127.26.63.1:44999)
I20260812 06:19:55.225391 26876 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016920412s
I20260812 06:19:55.226616 26918 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48036
I20260812 06:19:55.236138 26918 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48050:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:55.251583 27069 tablet_service.cc:1511] Processing CreateTablet for tablet ef14d1c88cd643e0beada843c416c11d (DEFAULT_TABLE table=heavy-update-compaction-test [id=263cddd3894d40f297c9313d7b436074]), partition=
I20260812 06:19:55.252089 27069 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ef14d1c88cd643e0beada843c416c11d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:55.254985 27143 tablet_bootstrap.cc:492] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Bootstrap starting.
I20260812 06:19:55.256029 27143 tablet_bootstrap.cc:654] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:55.257198 27143 tablet_bootstrap.cc:492] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: No bootstrap required, opened a new log
I20260812 06:19:55.257314 27143 ts_tablet_manager.cc:1403] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:55.257802 27143 raft_consensus.cc:359] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f662dd1ee3b047bf984d9f6e2e48f2b1" member_type: VOTER last_known_addr { host: "127.26.63.1" port: 44999 } }
I20260812 06:19:55.257906 27143 raft_consensus.cc:385] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:55.258018 27143 raft_consensus.cc:740] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f662dd1ee3b047bf984d9f6e2e48f2b1, State: Initialized, Role: FOLLOWER
I20260812 06:19:55.258342 27143 consensus_queue.cc:260] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1 [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: "f662dd1ee3b047bf984d9f6e2e48f2b1" member_type: VOTER last_known_addr { host: "127.26.63.1" port: 44999 } }
I20260812 06:19:55.258754 27143 raft_consensus.cc:399] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:55.258818 27143 raft_consensus.cc:493] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:55.258899 27143 raft_consensus.cc:3060] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:55.259732 27143 raft_consensus.cc:515] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f662dd1ee3b047bf984d9f6e2e48f2b1" member_type: VOTER last_known_addr { host: "127.26.63.1" port: 44999 } }
I20260812 06:19:55.259887 27143 leader_election.cc:304] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1 [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: f662dd1ee3b047bf984d9f6e2e48f2b1; no voters: 
I20260812 06:19:55.260155 27143 leader_election.cc:290] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:55.260258 27147 raft_consensus.cc:2804] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:55.260442 27147 raft_consensus.cc:697] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1 [term 1 LEADER]: Becoming Leader. State: Replica: f662dd1ee3b047bf984d9f6e2e48f2b1, State: Running, Role: LEADER
I20260812 06:19:55.260577 27143 ts_tablet_manager.cc:1434] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:55.260656 27147 consensus_queue.cc:237] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1 [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: "f662dd1ee3b047bf984d9f6e2e48f2b1" member_type: VOTER last_known_addr { host: "127.26.63.1" port: 44999 } }
I20260812 06:19:55.260815 27128 heartbeater.cc:499] Master 127.26.63.62:39175 was elected leader, sending a full tablet report...
I20260812 06:19:55.264016 26918 catalog_manager.cc:5719] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1 reported cstate change: term changed from 0 to 1, leader changed from <none> to f662dd1ee3b047bf984d9f6e2e48f2b1 (127.26.63.1). New cstate: current_term: 1 leader_uuid: "f662dd1ee3b047bf984d9f6e2e48f2b1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f662dd1ee3b047bf984d9f6e2e48f2b1" member_type: VOTER last_known_addr { host: "127.26.63.1" port: 44999 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:55.333117 26876 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.025s	sys 0.004s
I20260812 06:19:55.458938 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushMRSOp(ef14d1c88cd643e0beada843c416c11d): perf score=15.086190
I20260812 06:19:55.630093 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushMRSOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.171s	user 0.119s	sys 0.043s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":312,"delete_count":0,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1003,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41105,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":185,"threads_started":1,"update_count":1500}
I20260812 06:19:55.631599 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling LogGCOp(ef14d1c88cd643e0beada843c416c11d): free 8725963 bytes of WAL
I20260812 06:19:55.631940 27039 log_reader.cc:385] T ef14d1c88cd643e0beada843c416c11d: removed 1 log segments from log reader
I20260812 06:19:55.632025 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000001 (ops 1-6)
I20260812 06:19:55.634639 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: LogGCOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:55.635054 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:55.653946 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.019s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6356,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.654443 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling UndoDeltaBlockGCOp(ef14d1c88cd643e0beada843c416c11d): 12308958 bytes on disk
I20260812 06:19:55.655479 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: UndoDeltaBlockGCOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:19:55.655985 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:55.794159 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.138s	user 0.106s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":486,"lbm_read_time_us":8118,"lbm_reads_lt_1ms":460,"lbm_write_time_us":27711,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":305,"threads_started":5,"update_count":2000}
I20260812 06:19:55.794708 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=10.126437
I20260812 06:19:55.834774 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.040s	user 0.033s	sys 0.004s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17190,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.835304 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:55.848619 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5042,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.849114 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:55.983381 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.134s	user 0.110s	sys 0.024s 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":101,"lbm_read_time_us":9882,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26315,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":26368,"update_count":2000}
I20260812 06:19:55.984903 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=10.126437
I20260812 06:19:56.029670 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.044s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15616,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.030313 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:56.041714 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4176,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.042708 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:56.165475 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.123s	user 0.102s	sys 0.020s 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":239,"lbm_read_time_us":8978,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24230,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2000}
I20260812 06:19:56.166811 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=10.126437
I20260812 06:19:56.228806 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.062s	user 0.044s	sys 0.011s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19198,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.229521 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:56.241079 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4429,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.241611 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:56.409076 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.167s	user 0.101s	sys 0.065s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631315,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":247,"lbm_read_time_us":13174,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27815,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21376,"update_count":2000}
I20260812 06:19:56.409669 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=10.126437
I20260812 06:19:56.459391 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.049s	user 0.028s	sys 0.005s Metrics: {"bytes_written":12307495,"delete_count":0,"lbm_write_time_us":16000,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.459997 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:56.471988 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4497,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.472515 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:56.597718 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.125s	user 0.108s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631316,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":216,"lbm_read_time_us":9371,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25115,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2000}
I20260812 06:19:56.598366 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=10.126437
I20260812 06:19:56.637804 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.039s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16681,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.638406 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:56.649729 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4293,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.650431 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:56.774490 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.124s	user 0.111s	sys 0.012s 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":2233,"lbm_read_time_us":10756,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23189,"lbm_writes_lt_1ms":443,"mutex_wait_us":523,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17024,"update_count":2000}
I20260812 06:19:56.775230 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=10.126437
I20260812 06:19:56.833565 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.058s	user 0.026s	sys 0.023s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18811,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.834172 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:56.848783 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5824,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.849375 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushMRSOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:56.895705 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushMRSOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.046s	user 0.039s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":284,"dirs.run_wall_time_us":1541,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1444,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:56.896569 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling LogGCOp(ef14d1c88cd643e0beada843c416c11d): free 123804179 bytes of WAL
I20260812 06:19:56.896835 27039 log_reader.cc:385] T ef14d1c88cd643e0beada843c416c11d: removed 12 log segments from log reader
I20260812 06:19:56.896885 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000002 (ops 7-11)
I20260812 06:19:56.896942 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000003 (ops 12-16)
I20260812 06:19:56.896994 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000004 (ops 17-21)
I20260812 06:19:56.897045 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000005 (ops 22-26)
I20260812 06:19:56.897089 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000006 (ops 27-31)
I20260812 06:19:56.897109 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000007 (ops 32-36)
I20260812 06:19:56.897169 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000008 (ops 37-41)
I20260812 06:19:56.897212 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000009 (ops 42-46)
I20260812 06:19:56.897254 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000010 (ops 47-50)
I20260812 06:19:56.897296 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000011 (ops 51-55)
I20260812 06:19:56.897338 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000012 (ops 56-60)
I20260812 06:19:56.897379 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000013 (ops 61-64)
I20260812 06:19:56.928799 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: LogGCOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.032s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:19:56.929250 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling UndoDeltaBlockGCOp(ef14d1c88cd643e0beada843c416c11d): 447 bytes on disk
I20260812 06:19:56.929832 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: UndoDeltaBlockGCOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:56.930331 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=3.181125
I20260812 06:19:56.943464 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4765,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:56.944000 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:56.955173 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.011s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4136,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:56.955960 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:57.157727 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.202s	user 0.145s	sys 0.056s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836359,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":571,"lbm_read_time_us":14470,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34183,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":90,"threads_started":1,"update_count":3000}
I20260812 06:19:57.158486 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=14.095187
I20260812 06:19:57.227099 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.068s	user 0.028s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26032,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.227778 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:57.239362 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4082,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.239890 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:57.414021 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.174s	user 0.139s	sys 0.033s 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":434,"lbm_read_time_us":13483,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29880,"lbm_writes_lt_1ms":543,"mutex_wait_us":69,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:57.414609 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=14.095187
I20260812 06:19:57.477948 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.063s	user 0.033s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22372,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.478590 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:57.490922 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.012s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4753,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.491418 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:57.662544 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.171s	user 0.123s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1480,"lbm_read_time_us":13614,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29452,"lbm_writes_lt_1ms":543,"mutex_wait_us":361,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2500}
I20260812 06:19:57.663218 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=14.095187
I20260812 06:19:57.728413 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.065s	user 0.038s	sys 0.023s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22564,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.729063 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:57.741139 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4673,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.741674 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:57.938458 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.197s	user 0.124s	sys 0.060s 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":998,"lbm_read_time_us":14050,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33400,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:57.939109 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=14.095187
I20260812 06:19:57.990840 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.052s	user 0.033s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23297,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.991665 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:58.020788 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.029s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7646,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.021395 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:58.184290 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.163s	user 0.127s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":271,"lbm_read_time_us":11243,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26924,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2500}
I20260812 06:19:58.185168 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=14.095187
I20260812 06:19:58.239061 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.054s	user 0.018s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22627,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.239771 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:58.273239 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.033s	user 0.001s	sys 0.022s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5807,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.274051 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:58.285748 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4455,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.286413 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushMRSOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:58.331678 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushMRSOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.045s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":312,"dirs.run_wall_time_us":1605,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1522,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:58.332463 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling LogGCOp(ef14d1c88cd643e0beada843c416c11d): free 108988507 bytes of WAL
I20260812 06:19:58.332741 27039 log_reader.cc:385] T ef14d1c88cd643e0beada843c416c11d: removed 11 log segments from log reader
I20260812 06:19:58.332805 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000014 (ops 65-69)
I20260812 06:19:58.332847 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000015 (ops 70-74)
I20260812 06:19:58.332880 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000016 (ops 75-79)
I20260812 06:19:58.332906 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000017 (ops 80-84)
I20260812 06:19:58.332935 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000018 (ops 85-89)
I20260812 06:19:58.332965 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000019 (ops 90-94)
I20260812 06:19:58.333007 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000020 (ops 95-99)
I20260812 06:19:58.333039 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000021 (ops 100-104)
I20260812 06:19:58.333066 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000022 (ops 105-108)
I20260812 06:19:58.333096 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000023 (ops 109-113)
I20260812 06:19:58.333130 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000024 (ops 114-118)
I20260812 06:19:58.360646 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: LogGCOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:58.361260 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:58.390882 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.029s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5784,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.391403 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:58.402346 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4111,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.402865 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling UndoDeltaBlockGCOp(ef14d1c88cd643e0beada843c416c11d): 447 bytes on disk
I20260812 06:19:58.403570 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: UndoDeltaBlockGCOp(ef14d1c88cd643e0beada843c416c11d) 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:19:58.404323 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:58.667194 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.263s	user 0.176s	sys 0.080s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37041315,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":946,"lbm_read_time_us":18492,"lbm_reads_lt_1ms":875,"lbm_write_time_us":44866,"lbm_writes_lt_1ms":843,"mutex_wait_us":302,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":11008,"thread_start_us":80,"threads_started":1,"update_count":4000}
I20260812 06:19:58.667909 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=18.063937
I20260812 06:19:58.742223 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.074s	user 0.036s	sys 0.035s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":33599,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:58.742843 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:58.761940 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.019s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5830,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.762502 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:58.937168 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.175s	user 0.146s	sys 0.028s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836140,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":703,"lbm_read_time_us":13312,"lbm_reads_lt_1ms":664,"lbm_write_time_us":35180,"lbm_writes_lt_1ms":643,"mutex_wait_us":41,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20096,"update_count":3000}
I20260812 06:19:58.938079 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=14.095187
I20260812 06:19:58.989552 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.051s	user 0.025s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22377,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.990350 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:59.006285 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6111,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.007045 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:59.171655 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.164s	user 0.125s	sys 0.036s 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":1000,"lbm_read_time_us":9865,"lbm_reads_lt_1ms":568,"lbm_write_time_us":32805,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":296704,"update_count":2500}
I20260812 06:19:59.172410 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=14.095187
I20260812 06:19:59.236418 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.064s	user 0.031s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25573,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.237018 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:59.248147 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4180,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.248885 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:59.435981 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.187s	user 0.126s	sys 0.052s 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":1426,"lbm_read_time_us":13139,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33106,"lbm_writes_lt_1ms":543,"mutex_wait_us":401,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:19:59.436746 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=14.095187
I20260812 06:19:59.501250 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.064s	user 0.038s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":28506,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.501895 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:59.516953 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5533,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.517776 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:59.700639 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.183s	user 0.132s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":173,"lbm_read_time_us":13108,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30465,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:19:59.701267 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=14.095187
I20260812 06:19:59.765842 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.064s	user 0.020s	sys 0.041s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24297,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.766568 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:59.777657 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4183,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.778177 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushMRSOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:19:59.825959 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushMRSOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.048s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1152511,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":265,"dirs.run_wall_time_us":1499,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1507,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:59.826949 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling LogGCOp(ef14d1c88cd643e0beada843c416c11d): free 115943373 bytes of WAL
I20260812 06:19:59.827229 27039 log_reader.cc:385] T ef14d1c88cd643e0beada843c416c11d: removed 11 log segments from log reader
I20260812 06:19:59.827281 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000025 (ops 119-123)
I20260812 06:19:59.827315 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000026 (ops 124-128)
I20260812 06:19:59.827476 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000027 (ops 129-133)
I20260812 06:19:59.827574 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000028 (ops 134-138)
I20260812 06:19:59.827625 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000029 (ops 139-143)
I20260812 06:19:59.827667 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000030 (ops 144-148)
I20260812 06:19:59.827711 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000031 (ops 149-153)
I20260812 06:19:59.827752 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000032 (ops 154-158)
I20260812 06:19:59.827797 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000033 (ops 159-163)
I20260812 06:19:59.827837 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000034 (ops 164-168)
I20260812 06:19:59.827878 27039 log.cc:1079] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/ef14d1c88cd643e0beada843c416c11d/wal-000000035 (ops 169-173)
I20260812 06:19:59.856256 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: LogGCOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.029s	user 0.002s	sys 0.026s Metrics: {}
I20260812 06:19:59.856789 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:59.874039 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.017s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4225732,"delete_count":0,"lbm_write_time_us":4718,"lbm_writes_lt_1ms":106,"mutex_wait_us":123,"reinsert_count":0,"update_count":515}
I20260812 06:19:59.874579 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling UndoDeltaBlockGCOp(ef14d1c88cd643e0beada843c416c11d): 448 bytes on disk
I20260812 06:19:59.875067 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: UndoDeltaBlockGCOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:59.875698 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:19:59.896057 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.020s	user 0.012s	sys 0.005s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":6473,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:19:59.896687 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:20:00.144345 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.247s	user 0.168s	sys 0.074s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938783,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":901,"lbm_read_time_us":22827,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":765,"lbm_write_time_us":42284,"lbm_writes_lt_1ms":743,"mutex_wait_us":3,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:20:00.144948 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=18.063937
I20260812 06:20:00.217260 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.072s	user 0.039s	sys 0.032s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":32781,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:00.217796 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:20:00.230723 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5106,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.231258 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:20:00.397032 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.166s	user 0.123s	sys 0.042s 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":233,"lbm_read_time_us":10818,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34197,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":3000}
I20260812 06:20:00.397804 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=14.095187
I20260812 06:20:00.439953 26876 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.107s	user 1.877s	sys 0.146s
I20260812 06:20:00.453672 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.056s	user 0.014s	sys 0.040s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24233,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:20:00.454223 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d): perf score=2.188937
I20260812 06:20:00.464428 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: FlushDeltaMemStoresOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4175,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.464882 27131 maintenance_manager.cc:419] P f662dd1ee3b047bf984d9f6e2e48f2b1: Scheduling MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d): perf score=1.000000
I20260812 06:20:00.477766 26876 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.037s	user 0.001s	sys 0.000s
I20260812 06:20:00.478485 26876 tablet_server.cc:179] TabletServer@127.26.63.1:0 shutting down...
I20260812 06:20:00.587288 27039 maintenance_manager.cc:643] P f662dd1ee3b047bf984d9f6e2e48f2b1: MajorDeltaCompactionOp(ef14d1c88cd643e0beada843c416c11d) complete. Timing: real 0.122s	user 0.098s	sys 0.024s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4221425,"cfile_cache_miss":502,"cfile_cache_miss_bytes":20512299,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":446,"lbm_read_time_us":8142,"lbm_reads_lt_1ms":518,"lbm_write_time_us":25046,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2500}
I20260812 06:20:00.588279 26876 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:00.588769 26876 tablet_replica.cc:333] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1: stopping tablet replica
I20260812 06:20:00.589082 26876 raft_consensus.cc:2243] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:00.589357 26876 raft_consensus.cc:2272] T ef14d1c88cd643e0beada843c416c11d P f662dd1ee3b047bf984d9f6e2e48f2b1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:00.596580 26876 tablet_server.cc:196] TabletServer@127.26.63.1:0 shutdown complete.
I20260812 06:20:00.634465 26876 master.cc:562] Master@127.26.63.62:39175 shutting down...
I20260812 06:20:00.638742 26876 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:00.638942 26876 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:00.639010 26876 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9bc4fe4ea1f642fba0e6e2c1b11629f8: stopping tablet replica
I20260812 06:20:00.651903 26876 master.cc:584] Master@127.26.63.62:39175 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5773 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:00.772487 26876 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.63.62:39355
I20260812 06:20:00.772974 26876 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:00.775298 27186 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:00.775429 27180 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:00.775446 27177 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:00.775465 26876 server_base.cc:1061] running on GCE node
I20260812 06:20:00.776392 26876 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:00.776437 26876 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:00.776467 26876 hybrid_clock.cc:648] HybridClock initialized: now 1786515600776468 us; error 0 us; skew 500 ppm
I20260812 06:20:00.777330 26876 webserver.cc:533] Webserver started at http://127.26.63.62:37467/ using document root <none> and password file <none>
I20260812 06:20:00.777474 26876 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:00.777515 26876 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:00.777580 26876 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:00.777953 26876 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/master-0-root/instance:
uuid: "7225bd91a98d41f9a65d60009c56476d"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-sb2z"
I20260812 06:20:00.779511 26876 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:00.780628 27195 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.780933 26876 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:00.781003 26876 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/master-0-root
uuid: "7225bd91a98d41f9a65d60009c56476d"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-sb2z"
I20260812 06:20:00.781116 26876 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-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:00.793224 26876 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:00.793699 26876 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:00.798164 26876 rpc_server.cc:307] RPC server started. Bound to: 127.26.63.62:39355
I20260812 06:20:00.801086 27274 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.63.62:39355 every 8 connection(s)
I20260812 06:20:00.801748 27276 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:00.803961 27276 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d: Bootstrap starting.
I20260812 06:20:00.805027 27276 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:00.806198 27276 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d: No bootstrap required, opened a new log
I20260812 06:20:00.806701 27276 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7225bd91a98d41f9a65d60009c56476d" member_type: VOTER }
I20260812 06:20:00.806802 27276 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:00.806869 27276 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7225bd91a98d41f9a65d60009c56476d, State: Initialized, Role: FOLLOWER
I20260812 06:20:00.807087 27276 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [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: "7225bd91a98d41f9a65d60009c56476d" member_type: VOTER }
I20260812 06:20:00.807193 27276 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:00.807255 27276 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:00.807325 27276 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:00.808205 27276 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7225bd91a98d41f9a65d60009c56476d" member_type: VOTER }
I20260812 06:20:00.808380 27276 leader_election.cc:304] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [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: 7225bd91a98d41f9a65d60009c56476d; no voters: 
I20260812 06:20:00.808640 27276 leader_election.cc:290] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:00.808789 27283 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:00.809022 27283 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [term 1 LEADER]: Becoming Leader. State: Replica: 7225bd91a98d41f9a65d60009c56476d, State: Running, Role: LEADER
I20260812 06:20:00.809187 27283 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [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: "7225bd91a98d41f9a65d60009c56476d" member_type: VOTER }
I20260812 06:20:00.809265 27276 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:00.809669 27285 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7225bd91a98d41f9a65d60009c56476d. Latest consensus state: current_term: 1 leader_uuid: "7225bd91a98d41f9a65d60009c56476d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7225bd91a98d41f9a65d60009c56476d" member_type: VOTER } }
I20260812 06:20:00.809654 27284 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7225bd91a98d41f9a65d60009c56476d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7225bd91a98d41f9a65d60009c56476d" member_type: VOTER } }
I20260812 06:20:00.809804 27285 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:00.809866 27284 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:00.810148 27288 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:00.811024 27288 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:00.811614 26876 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:00.813184 27288 catalog_manager.cc:1383] Generated new cluster ID: c544160c34bd43a4b03b3fe9643b6e65
I20260812 06:20:00.813277 27288 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:00.817708 27288 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:00.818281 27288 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:00.831710 27288 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d: Generated new TSK 0
I20260812 06:20:00.831928 27288 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:00.844245 26876 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:00.846678 27310 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:00.846798 27313 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:00.846833 26876 server_base.cc:1061] running on GCE node
W20260812 06:20:00.846803 27311 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:00.847321 26876 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:00.847368 26876 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:00.847385 26876 hybrid_clock.cc:648] HybridClock initialized: now 1786515600847386 us; error 0 us; skew 500 ppm
I20260812 06:20:00.848418 26876 webserver.cc:533] Webserver started at http://127.26.63.1:38479/ using document root <none> and password file <none>
I20260812 06:20:00.848567 26876 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:00.848619 26876 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:00.848677 26876 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:00.849031 26876 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/instance:
uuid: "ccb8332991284edbb6ab9da6c44ecf79"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-sb2z"
I20260812 06:20:00.850558 26876 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:00.851657 27322 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.852072 26876 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:00.852159 26876 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root
uuid: "ccb8332991284edbb6ab9da6c44ecf79"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-sb2z"
I20260812 06:20:00.852260 26876 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:00.864192 26876 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:00.864665 26876 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:00.865002 26876 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:00.865506 26876 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:00.865566 26876 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.865617 26876 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:00.865669 26876 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.870275 26876 rpc_server.cc:307] RPC server started. Bound to: 127.26.63.1:46017
I20260812 06:20:00.870811 27422 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.63.1:46017 every 8 connection(s)
I20260812 06:20:00.880501 27424 heartbeater.cc:344] Connected to a master server at 127.26.63.62:39355
I20260812 06:20:00.880693 27424 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:00.881078 27424 heartbeater.cc:507] Master 127.26.63.62:39355 requested a full tablet report, sending...
I20260812 06:20:00.881862 27221 ts_manager.cc:194] Registered new tserver with Master: ccb8332991284edbb6ab9da6c44ecf79 (127.26.63.1:46017)
I20260812 06:20:00.882164 26876 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011178847s
I20260812 06:20:00.882688 27221 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60748
I20260812 06:20:00.890173 27221 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60762:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:00.899876 27365 tablet_service.cc:1511] Processing CreateTablet for tablet 1c9216d0dd2b448eb2a39208ed40fd80 (DEFAULT_TABLE table=heavy-update-compaction-test [id=22343c2128d746a89f0aaaccbf00e316]), partition=
I20260812 06:20:00.900208 27365 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1c9216d0dd2b448eb2a39208ed40fd80. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:00.902311 27442 tablet_bootstrap.cc:492] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Bootstrap starting.
I20260812 06:20:00.903234 27442 tablet_bootstrap.cc:654] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:00.904472 27442 tablet_bootstrap.cc:492] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: No bootstrap required, opened a new log
I20260812 06:20:00.904582 27442 ts_tablet_manager.cc:1403] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:00.905036 27442 raft_consensus.cc:359] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ccb8332991284edbb6ab9da6c44ecf79" member_type: VOTER last_known_addr { host: "127.26.63.1" port: 46017 } }
I20260812 06:20:00.905175 27442 raft_consensus.cc:385] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:00.905217 27442 raft_consensus.cc:740] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ccb8332991284edbb6ab9da6c44ecf79, State: Initialized, Role: FOLLOWER
I20260812 06:20:00.905438 27442 consensus_queue.cc:260] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79 [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: "ccb8332991284edbb6ab9da6c44ecf79" member_type: VOTER last_known_addr { host: "127.26.63.1" port: 46017 } }
I20260812 06:20:00.905629 27442 raft_consensus.cc:399] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:00.905710 27442 raft_consensus.cc:493] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:00.905789 27442 raft_consensus.cc:3060] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:00.906599 27442 raft_consensus.cc:515] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ccb8332991284edbb6ab9da6c44ecf79" member_type: VOTER last_known_addr { host: "127.26.63.1" port: 46017 } }
I20260812 06:20:00.906750 27442 leader_election.cc:304] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79 [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: ccb8332991284edbb6ab9da6c44ecf79; no voters: 
I20260812 06:20:00.907034 27442 leader_election.cc:290] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:00.907188 27444 raft_consensus.cc:2804] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:00.907446 27444 raft_consensus.cc:697] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79 [term 1 LEADER]: Becoming Leader. State: Replica: ccb8332991284edbb6ab9da6c44ecf79, State: Running, Role: LEADER
I20260812 06:20:00.907444 27424 heartbeater.cc:499] Master 127.26.63.62:39355 was elected leader, sending a full tablet report...
I20260812 06:20:00.907444 27442 ts_tablet_manager.cc:1434] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:00.907642 27444 consensus_queue.cc:237] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79 [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: "ccb8332991284edbb6ab9da6c44ecf79" member_type: VOTER last_known_addr { host: "127.26.63.1" port: 46017 } }
I20260812 06:20:00.909044 27221 catalog_manager.cc:5719] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79 reported cstate change: term changed from 0 to 1, leader changed from <none> to ccb8332991284edbb6ab9da6c44ecf79 (127.26.63.1). New cstate: current_term: 1 leader_uuid: "ccb8332991284edbb6ab9da6c44ecf79" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ccb8332991284edbb6ab9da6c44ecf79" member_type: VOTER last_known_addr { host: "127.26.63.1" port: 46017 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:00.972342 26876 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.016s	sys 0.008s
I20260812 06:20:01.121524 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushMRSOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=19.054940
I20260812 06:20:01.293334 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushMRSOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.171s	user 0.114s	sys 0.055s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":99,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":1052,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42286,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:20:01.294142 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling LogGCOp(1c9216d0dd2b448eb2a39208ed40fd80): free 20743880 bytes of WAL
I20260812 06:20:01.294399 27329 log_reader.cc:385] T 1c9216d0dd2b448eb2a39208ed40fd80: removed 2 log segments from log reader
I20260812 06:20:01.294449 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000001 (ops 1-6)
I20260812 06:20:01.294481 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000002 (ops 7-11)
I20260812 06:20:01.299117 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: LogGCOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:01.299587 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling UndoDeltaBlockGCOp(1c9216d0dd2b448eb2a39208ed40fd80): 16411393 bytes on disk
I20260812 06:20:01.300117 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: UndoDeltaBlockGCOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:20:01.300576 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:01.315017 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5303,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.315598 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:01.505316 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.189s	user 0.123s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":505,"lbm_read_time_us":15024,"lbm_reads_lt_1ms":460,"lbm_write_time_us":27930,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":336,"threads_started":5,"update_count":2000}
I20260812 06:20:01.505967 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=11.118625
I20260812 06:20:01.550318 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.044s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":20402,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:01.550817 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:01.573534 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.023s	user 0.011s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5796,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.573994 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:01.589740 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5916,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.590394 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:01.758046 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.167s	user 0.112s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":185,"lbm_read_time_us":11776,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32671,"lbm_writes_lt_1ms":543,"mutex_wait_us":117,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:20:01.758867 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=11.118625
I20260812 06:20:01.812081 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.053s	user 0.022s	sys 0.027s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":22967,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:01.812619 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:01.824891 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4452,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.825578 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:01.840857 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.015s	user 0.002s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5968,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.841564 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:02.006841 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.165s	user 0.105s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":381,"lbm_read_time_us":11712,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34141,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2500}
I20260812 06:20:02.007691 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=11.118625
I20260812 06:20:02.055186 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.047s	user 0.026s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":22047,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:02.055786 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:02.078328 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.022s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4186,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.078907 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:02.090667 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4542,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.091197 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:02.256807 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.165s	user 0.133s	sys 0.031s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":999,"lbm_read_time_us":13338,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31578,"lbm_writes_lt_1ms":543,"mutex_wait_us":366,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2500}
I20260812 06:20:02.257884 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=10.126437
I20260812 06:20:02.297820 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.040s	user 0.034s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16624,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:02.298415 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:02.313632 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5490,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.314127 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:02.450145 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.136s	user 0.120s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1789,"lbm_read_time_us":8923,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26923,"lbm_writes_lt_1ms":443,"mutex_wait_us":434,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:20:02.450899 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=10.126437
I20260812 06:20:02.505883 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.055s	user 0.021s	sys 0.031s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20653,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":1500}
I20260812 06:20:02.506669 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:02.519515 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4503,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.520226 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:02.680761 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.160s	user 0.100s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":258,"lbm_read_time_us":11981,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27034,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2000}
I20260812 06:20:02.681730 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=11.118625
I20260812 06:20:02.722577 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.041s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17462,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:02.723125 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:02.747120 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.024s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5736,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.747807 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:02.760646 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4643,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.761224 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushMRSOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:02.806445 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushMRSOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.045s	user 0.034s	sys 0.003s Metrics: {"bytes_written":1316413,"cfile_init":1,"dirs.queue_time_us":106,"dirs.run_cpu_time_us":270,"dirs.run_wall_time_us":1382,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1964,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:02.807236 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling LogGCOp(1c9216d0dd2b448eb2a39208ed40fd80): free 132571306 bytes of WAL
I20260812 06:20:02.807507 27329 log_reader.cc:385] T 1c9216d0dd2b448eb2a39208ed40fd80: removed 13 log segments from log reader
I20260812 06:20:02.807614 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000003 (ops 12-16)
I20260812 06:20:02.807664 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000004 (ops 17-21)
I20260812 06:20:02.807709 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000005 (ops 22-26)
I20260812 06:20:02.807767 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000006 (ops 27-31)
I20260812 06:20:02.807808 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000007 (ops 32-36)
I20260812 06:20:02.807850 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000008 (ops 37-41)
I20260812 06:20:02.807883 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000009 (ops 42-46)
I20260812 06:20:02.807914 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000010 (ops 47-50)
I20260812 06:20:02.807945 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000011 (ops 51-55)
I20260812 06:20:02.807981 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000012 (ops 56-60)
I20260812 06:20:02.808046 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000013 (ops 61-64)
I20260812 06:20:02.808085 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000014 (ops 65-69)
I20260812 06:20:02.808108 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000015 (ops 70-74)
I20260812 06:20:02.837154 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: LogGCOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.030s	user 0.000s	sys 0.028s Metrics: {"spinlock_wait_cycles":58240}
I20260812 06:20:02.838291 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling UndoDeltaBlockGCOp(1c9216d0dd2b448eb2a39208ed40fd80): 493 bytes on disk
I20260812 06:20:02.838747 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: UndoDeltaBlockGCOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:20:02.839231 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=6.157687
I20260812 06:20:02.861102 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.022s	user 0.014s	sys 0.006s Metrics: {"bytes_written":7876884,"delete_count":0,"lbm_write_time_us":8856,"lbm_writes_lt_1ms":195,"reinsert_count":0,"update_count":960}
I20260812 06:20:02.861629 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:03.124677 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.263s	user 0.130s	sys 0.132s Metrics: {"cfile_cache_miss":726,"cfile_cache_miss_bytes":32651550,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":286,"lbm_read_time_us":16678,"lbm_reads_lt_1ms":758,"lbm_write_time_us":44859,"lbm_writes_lt_1ms":735,"mutex_wait_us":27,"peak_mem_usage":86600380,"reinsert_count":0,"spinlock_wait_cycles":14720,"thread_start_us":90,"threads_started":1,"update_count":3460}
I20260812 06:20:03.125554 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=19.056125
I20260812 06:20:03.182575 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.057s	user 0.034s	sys 0.020s Metrics: {"bytes_written":20840514,"delete_count":0,"lbm_write_time_us":25400,"lbm_writes_lt_1ms":511,"reinsert_count":0,"update_count":2540}
I20260812 06:20:03.183156 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:03.378854 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.196s	user 0.128s	sys 0.064s Metrics: {"cfile_cache_miss":539,"cfile_cache_miss_bytes":25102770,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":656,"lbm_read_time_us":14162,"lbm_reads_lt_1ms":575,"lbm_write_time_us":34423,"lbm_writes_lt_1ms":551,"mutex_wait_us":27,"peak_mem_usage":63444180,"reinsert_count":0,"spinlock_wait_cycles":785280,"update_count":2540}
I20260812 06:20:03.379630 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=14.095187
I20260812 06:20:03.448072 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.068s	user 0.031s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23269,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.448673 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:03.460151 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4476,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.460704 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:03.651163 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.190s	user 0.136s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":529,"lbm_read_time_us":13956,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31001,"lbm_writes_lt_1ms":543,"mutex_wait_us":294,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:20:03.651836 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=14.095187
I20260812 06:20:03.716174 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.064s	user 0.043s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23659,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.716856 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:03.729182 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4341,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.729753 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:03.943974 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.214s	user 0.135s	sys 0.075s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":589,"lbm_read_time_us":15931,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35408,"lbm_writes_lt_1ms":543,"mutex_wait_us":289,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:20:03.945155 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=11.118625
I20260812 06:20:03.986392 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.041s	user 0.021s	sys 0.017s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17357,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:03.987056 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:04.004386 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5767,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:04.004997 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:04.147060 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.142s	user 0.118s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":700,"lbm_read_time_us":9381,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27477,"lbm_writes_lt_1ms":443,"mutex_wait_us":304,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2000}
I20260812 06:20:04.147787 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=10.126437
I20260812 06:20:04.219033 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.071s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":40773,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.219630 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=6.157687
I20260812 06:20:04.246591 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.027s	user 0.021s	sys 0.000s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9694,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:04.247452 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:04.393632 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.146s	user 0.106s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":861,"lbm_read_time_us":9950,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28339,"lbm_writes_lt_1ms":543,"mutex_wait_us":350,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:20:04.394282 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=14.095187
I20260812 06:20:04.440922 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.046s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20321,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.441615 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:04.453974 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4033,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.454752 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushMRSOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:04.484299 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushMRSOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.029s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":265,"dirs.run_wall_time_us":1650,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1713,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:04.484973 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling LogGCOp(1c9216d0dd2b448eb2a39208ed40fd80): free 129320545 bytes of WAL
I20260812 06:20:04.485224 27329 log_reader.cc:385] T 1c9216d0dd2b448eb2a39208ed40fd80: removed 13 log segments from log reader
I20260812 06:20:04.485270 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000016 (ops 75-79)
I20260812 06:20:04.485301 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000017 (ops 80-84)
I20260812 06:20:04.485364 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000018 (ops 85-88)
I20260812 06:20:04.485397 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000019 (ops 89-93)
I20260812 06:20:04.485433 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000020 (ops 94-98)
I20260812 06:20:04.485479 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000021 (ops 99-102)
I20260812 06:20:04.485520 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000022 (ops 103-107)
I20260812 06:20:04.485562 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000023 (ops 108-112)
I20260812 06:20:04.485602 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000024 (ops 113-117)
I20260812 06:20:04.485642 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000025 (ops 118-122)
I20260812 06:20:04.485687 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000026 (ops 123-127)
I20260812 06:20:04.485729 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000027 (ops 128-132)
I20260812 06:20:04.485769 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000028 (ops 133-137)
I20260812 06:20:04.518126 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: LogGCOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:04.518719 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling UndoDeltaBlockGCOp(1c9216d0dd2b448eb2a39208ed40fd80): 482 bytes on disk
I20260812 06:20:04.519379 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: UndoDeltaBlockGCOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:20:04.520040 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=4.173312
I20260812 06:20:04.536523 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":6071825,"delete_count":0,"lbm_write_time_us":6714,"lbm_writes_lt_1ms":151,"reinsert_count":0,"update_count":740}
I20260812 06:20:04.537042 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:04.547916 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":2133453,"delete_count":0,"lbm_write_time_us":3350,"lbm_writes_lt_1ms":55,"reinsert_count":0,"update_count":260}
I20260812 06:20:04.548463 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:04.747337 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.199s	user 0.149s	sys 0.048s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979706,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":701,"lbm_read_time_us":15605,"lbm_reads_lt_1ms":766,"lbm_write_time_us":39447,"lbm_writes_lt_1ms":743,"mutex_wait_us":73,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":81792,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:20:04.748128 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=15.087375
I20260812 06:20:04.817167 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.069s	user 0.052s	sys 0.011s Metrics: {"bytes_written":16820148,"delete_count":0,"lbm_write_time_us":27352,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:04.817847 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:04.834813 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6742,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.835309 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:04.845315 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3638,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:04.845896 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:05.027262 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.181s	user 0.145s	sys 0.036s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877212,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":302,"lbm_read_time_us":14965,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34586,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":27136,"update_count":3000}
I20260812 06:20:05.028225 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=11.118625
I20260812 06:20:05.075094 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.047s	user 0.029s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18174,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:05.075942 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:05.092540 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.016s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5161,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.093025 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:05.103355 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3879,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:05.103914 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:05.264648 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.161s	user 0.101s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":73,"lbm_read_time_us":10518,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30515,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:05.265341 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=11.118625
I20260812 06:20:05.312919 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.047s	user 0.022s	sys 0.024s Metrics: {"bytes_written":12676711,"delete_count":0,"lbm_write_time_us":21661,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1545}
I20260812 06:20:05.313397 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:05.338225 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.025s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":5515,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:20:05.338719 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:05.349275 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3998,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.349805 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:05.548303 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.198s	user 0.131s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774804,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":267,"lbm_read_time_us":10662,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33909,"lbm_writes_lt_1ms":543,"mutex_wait_us":75,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":55168,"update_count":2500}
I20260812 06:20:05.548913 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=14.095187
I20260812 06:20:05.605049 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.056s	user 0.027s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24064,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.605572 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:05.764230 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.158s	user 0.108s	sys 0.041s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":170,"lbm_read_time_us":9632,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27213,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24704,"update_count":2000}
I20260812 06:20:05.764889 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=14.095187
I20260812 06:20:05.820153 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.055s	user 0.040s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23234,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.820672 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:05.833288 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4373,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.833978 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:06.017023 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.183s	user 0.130s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":259,"lbm_read_time_us":10285,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31854,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:20:06.017716 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=14.095187
I20260812 06:20:06.066659 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.049s	user 0.023s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21813,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.067211 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:06.079727 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.012s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4793,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.080259 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushMRSOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:06.113261 26876 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.141s	user 1.896s	sys 0.164s
I20260812 06:20:06.121095 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushMRSOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.041s	user 0.039s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":272,"dirs.run_wall_time_us":1487,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2132,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:06.121903 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling LogGCOp(1c9216d0dd2b448eb2a39208ed40fd80): free 132571600 bytes of WAL
I20260812 06:20:06.122179 27329 log_reader.cc:385] T 1c9216d0dd2b448eb2a39208ed40fd80: removed 13 log segments from log reader
I20260812 06:20:06.122231 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000029 (ops 138-142)
I20260812 06:20:06.122263 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000030 (ops 143-147)
I20260812 06:20:06.122330 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000031 (ops 148-152)
I20260812 06:20:06.122397 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000032 (ops 153-157)
I20260812 06:20:06.122466 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000033 (ops 158-162)
I20260812 06:20:06.122519 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000034 (ops 163-166)
I20260812 06:20:06.122567 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000035 (ops 167-171)
I20260812 06:20:06.122611 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000036 (ops 172-176)
I20260812 06:20:06.122655 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000037 (ops 177-180)
I20260812 06:20:06.122702 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000038 (ops 181-185)
I20260812 06:20:06.122747 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000039 (ops 186-190)
I20260812 06:20:06.122787 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000040 (ops 191-195)
I20260812 06:20:06.122830 27329 log.cc:1079] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: Deleting log segment in path: /tmp/dist-test-taske30Q2a/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594973587-26876-0/minicluster-data/ts-0-root/wals/1c9216d0dd2b448eb2a39208ed40fd80/wal-000000041 (ops 196-200)
I20260812 06:20:06.152310 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: LogGCOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.030s	user 0.003s	sys 0.026s Metrics: {}
I20260812 06:20:06.152784 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=2.188937
I20260812 06:20:06.173163 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: FlushDeltaMemStoresOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.020s	user 0.011s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4539,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.173787 27425 maintenance_manager.cc:419] P ccb8332991284edbb6ab9da6c44ecf79: Scheduling MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80): perf score=1.000000
I20260812 06:20:06.174281 26876 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.061s	user 0.004s	sys 0.000s
I20260812 06:20:06.174811 26876 tablet_server.cc:179] TabletServer@127.26.63.1:0 shutting down...
I20260812 06:20:06.328845 27329 maintenance_manager.cc:643] P ccb8332991284edbb6ab9da6c44ecf79: MajorDeltaCompactionOp(1c9216d0dd2b448eb2a39208ed40fd80) complete. Timing: real 0.155s	user 0.095s	sys 0.060s Metrics: {"cfile_cache_hit":532,"cfile_cache_hit_bytes":24774688,"cfile_cache_miss":101,"cfile_cache_miss_bytes":4102531,"cfile_init":3,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":619,"lbm_read_time_us":1812,"lbm_reads_lt_1ms":113,"lbm_write_time_us":29411,"lbm_writes_lt_1ms":643,"mutex_wait_us":81,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15744,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:20:06.329496 26876 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:06.329869 26876 tablet_replica.cc:333] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79: stopping tablet replica
I20260812 06:20:06.330030 26876 raft_consensus.cc:2243] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:06.330243 26876 raft_consensus.cc:2272] T 1c9216d0dd2b448eb2a39208ed40fd80 P ccb8332991284edbb6ab9da6c44ecf79 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:06.344906 26876 tablet_server.cc:196] TabletServer@127.26.63.1:0 shutdown complete.
I20260812 06:20:06.380263 26876 master.cc:562] Master@127.26.63.62:39355 shutting down...
I20260812 06:20:06.384164 26876 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:06.384361 26876 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:06.384413 26876 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7225bd91a98d41f9a65d60009c56476d: stopping tablet replica
I20260812 06:20:06.396907 26876 master.cc:584] Master@127.26.63.62:39355 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5729 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11503 ms total)

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